diff --git a/Cargo.lock b/Cargo.lock index dfe0bd5eac0..42487787eba 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -3559,7 +3559,7 @@ dependencies = [ [[package]] name = "mithril-common" -version = "0.4.53" +version = "0.4.54" dependencies = [ "anyhow", "async-trait", @@ -3600,7 +3600,6 @@ dependencies = [ "sha2", "slog", "slog-async", - "slog-scope", "slog-term", "strum", "thiserror", diff --git a/mithril-common/Cargo.toml b/mithril-common/Cargo.toml index 247afa6eb35..293da6558a8 100644 --- a/mithril-common/Cargo.toml +++ b/mithril-common/Cargo.toml @@ -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"] } diff --git a/mithril-common/src/cardano_block_scanner/chain_reader_block_streamer.rs b/mithril-common/src/cardano_block_scanner/chain_reader_block_streamer.rs index 0397ba9622d..4cdadc92192 100644 --- a/mithril-common/src/cardano_block_scanner/chain_reader_block_streamer.rs +++ b/mithril-common/src/cardano_block_scanner/chain_reader_block_streamer.rs @@ -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> { - 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::(), }) } @@ -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) } } diff --git a/mithril-common/src/cardano_transactions_preloader.rs b/mithril-common/src/cardano_transactions_preloader.rs index 7b6c0139fa7..e7c6af6a5b2 100644 --- a/mithril-common/src/cardano_transactions_preloader.rs +++ b/mithril-common/src/cardano_transactions_preloader.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,7 +72,7 @@ impl CardanoTransactionsPreloader { importer, security_parameter, chain_observer, - logger, + logger: logger.new_with_component_name::(), activation_state, } } @@ -79,26 +80,23 @@ impl CardanoTransactionsPreloader { /// 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 } diff --git a/mithril-common/src/certificate_chain/certificate_verifier.rs b/mithril-common/src/certificate_chain/certificate_verifier.rs index addb1391234..4124982413f 100644 --- a/mithril-common/src/certificate_chain/certificate_verifier.rs +++ b/mithril-common/src/certificate_chain/certificate_verifier.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) -> Self { debug!(logger, "New MithrilCertificateVerifier created"); Self { - logger, + logger: logger.new_with_component_name::(), 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 diff --git a/mithril-common/src/chain_reader/pallas_chain_reader.rs b/mithril-common/src/chain_reader/pallas_chain_reader.rs index 6336dfbe72b..bba62973b19 100644 --- a/mithril-common/src/chain_reader/pallas_chain_reader.rs +++ b/mithril-common/src/chain_reader/pallas_chain_reader.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::(), } } @@ -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(()) diff --git a/mithril-common/src/digesters/cache/json_provider_builder.rs b/mithril-common/src/digesters/cache/json_provider_builder.rs index 8db66e7d72c..34e561bd729 100644 --- a/mithril-common/src/digesters/cache/json_provider_builder.rs +++ b/mithril-common/src/digesters/cache/json_provider_builder.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 } diff --git a/mithril-common/src/digesters/cardano_immutable_digester.rs b/mithril-common/src/digesters/cardano_immutable_digester.rs index 1d0aa9f797a..6a114741252 100644 --- a/mithril-common/src/digesters/cardano_immutable_digester.rs +++ b/mithril-common/src/digesters/cardano_immutable_digester.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::(), } } } diff --git a/mithril-common/src/lib.rs b/mithril-common/src/lib.rs index 168b7f2b51f..f59d286641c 100644 --- a/mithril-common/src/lib.rs +++ b/mithril-common/src/lib.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; diff --git a/mithril-common/src/logging.rs b/mithril-common/src/logging.rs new file mode 100644 index 00000000000..ff275b9e202 --- /dev/null +++ b/mithril-common/src/logging.rs @@ -0,0 +1,83 @@ +//! Logging utilities for the Mithril project. + +use slog::Logger; + +/// Extension trait for `slog::Logger` +pub trait LoggerExtensions { + /// Create a new child logger with a `src` key containing the component name. + fn new_with_component_name(&self) -> Self; +} + +impl LoggerExtensions for Logger { + fn new_with_component_name(&self) -> Self { + self.new(slog::o!("src" => component_name::())) + } +} + +fn component_name() -> &'static str { + let complete_name = std::any::type_name::(); + complete_name.split("::").last().unwrap_or(complete_name) +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::test_utils::{TempDir, TestLogger}; + use slog::info; + + struct TestStruct; + #[allow( + dead_code, + reason = "A field is needed to add the lifetime but is unused" + )] + struct TestStructWithLifetime<'a>(&'a str); + enum TestEnum {} + + mod test_mod { + pub struct ScopedTestStruct; + pub enum ScopedTestEnum {} + } + + impl TestStruct { + fn self_component_name() -> &'static str { + component_name::() + } + } + + #[test] + fn extract_component_name_remove_namespaces() { + assert_eq!(component_name::(), "TestStruct"); + assert_eq!(component_name::(), "TestEnum"); + assert_eq!( + component_name::(), + "ScopedTestStruct" + ); + assert_eq!( + component_name::(), + "ScopedTestEnum" + ); + assert_eq!(TestStruct::self_component_name(), "TestStruct"); + assert_eq!( + component_name::(), + "TestStructWithLifetime" + ); + } + + #[test] + fn logger_extension_new_with_component_name() { + let log_path = + TempDir::create("common_logging", "logger_extension_new_with_component_name") + .join("test.log"); + { + let root_logger = TestLogger::file(&log_path); + let child_logger = root_logger.new_with_component_name::(); + info!(child_logger, "Child log"); + } + + let logs = std::fs::read_to_string(&log_path).unwrap(); + assert!( + logs.contains("src") && logs.contains("TestStruct"), + "log should contain `src` key for `TestStruct` as component name was provided, logs:\n{logs}" + ); + } +} diff --git a/mithril-common/src/signable_builder/cardano_immutable_full_signable_builder.rs b/mithril-common/src/signable_builder/cardano_immutable_full_signable_builder.rs index e55e0bee0c1..8f107263dcc 100644 --- a/mithril-common/src/signable_builder/cardano_immutable_full_signable_builder.rs +++ b/mithril-common/src/signable_builder/cardano_immutable_full_signable_builder.rs @@ -6,6 +6,7 @@ use std::{ use crate::{ digesters::ImmutableDigester, entities::{CardanoDbBeacon, ProtocolMessage, ProtocolMessagePartKey}, + logging::LoggerExtensions, signable_builder::SignableBuilder, StdResult, }; @@ -29,7 +30,7 @@ impl CardanoImmutableFilesFullSignableBuilder { ) -> Self { Self { immutable_digester, - logger, + logger: logger.new_with_component_name::(), dirpath: dirpath.to_owned(), } } @@ -41,7 +42,7 @@ impl SignableBuilder for CardanoImmutableFilesFullSignableBuild &self, beacon: CardanoDbBeacon, ) -> StdResult { - debug!(self.logger, "SignableBuilder::compute_signable({beacon:?})"); + debug!(self.logger, "compute_signable({beacon:?})"); let digest = self .immutable_digester .compute_digest(&self.dirpath, &beacon) @@ -52,7 +53,7 @@ impl SignableBuilder for CardanoImmutableFilesFullSignableBuild &self.dirpath.display() ) })?; - info!(self.logger, "SignableBuilder: digest = '{digest}'."); + info!(self.logger, "digest = '{digest}'."); let mut protocol_message = ProtocolMessage::new(); protocol_message.set_message_part(ProtocolMessagePartKey::SnapshotDigest, digest); diff --git a/mithril-common/src/signable_builder/cardano_transactions.rs b/mithril-common/src/signable_builder/cardano_transactions.rs index ac95349095c..7b99884ad6a 100644 --- a/mithril-common/src/signable_builder/cardano_transactions.rs +++ b/mithril-common/src/signable_builder/cardano_transactions.rs @@ -7,6 +7,7 @@ use slog::{debug, Logger}; use crate::{ crypto_helper::{MKMap, MKMapNode, MKTreeNode, MKTreeStorer}, entities::{BlockNumber, BlockRange, ProtocolMessage, ProtocolMessagePartKey}, + logging::LoggerExtensions, signable_builder::SignableBuilder, StdResult, }; @@ -65,7 +66,7 @@ impl CardanoTransactionsSignableBuilder { Self { transaction_importer, block_range_root_retriever, - logger, + logger: logger.new_with_component_name::(), } } } @@ -113,8 +114,7 @@ mod tests { fn compute_mk_map_from_transactions( transactions: Vec, - ) -> MKMap, MKTreeStoreInMemory> - { + ) -> MKMap, MKTreeStoreInMemory> { MKMap::new_from_iter(transactions.iter().map(|tx| { ( BlockRange::from_block_number(tx.block_number),