Merge pull request #1992 from input-output-hk/djo/1981/enhance_logs_in_signer

Enhance logs in mithril-signer and mithril-persistence

Author: Alenar

Cargo.lock

@@ -1,6 +1,6 @@
 [package]
 name = "mithril-persistence"
-version = "0.2.27"
+version = "0.2.28"
 description = "Common types, interfaces, and utilities to persist data for Mithril nodes."
 authors = { workspace = true }
 edition = { workspace = true }
@@ -29,7 +29,4 @@ tokio = { version = "1.40.0", features = ["sync"] }
 [dev-dependencies]
 mithril-common = { path = "../../mithril-common", features = ["test_tools"] }
 mockall = "0.13.0"
-slog-async = "2.8.0"
-slog-scope = "4.4.0"
-slog-term = "2.9.1"
 tokio = { version = "1.40.0", features = ["macros", "time"] }

internal/mithril-persistence/Cargo.toml

@@ -1,9 +1,11 @@
 use anyhow::{anyhow, Context};
 use chrono::Utc;
-use mithril_common::StdResult;
 use slog::{debug, error, info, Logger};
 use std::{cmp::Ordering, collections::BTreeSet};
 
+use mithril_common::logging::LoggerExtensions;
+use mithril_common::StdResult;
+
 use super::{
     ApplicationNodeType, DatabaseVersion, DbVersion, GetDatabaseVersionQuery,
     UpdateDatabaseVersionQuery,
@@ -38,7 +40,7 @@ impl<'conn> DatabaseVersionChecker<'conn> {
         Self {
             connection,
             application_type,
-            logger,
+            logger: logger.new_with_component_name::<Self>(),
             migrations,
         }
     }
@@ -203,6 +205,10 @@ mod tests {
 
     use super::*;
 
+    fn discard_logger() -> Logger {
+        Logger::root(slog::Discard, slog::o!())
+    }
+
     fn check_database_version(connection: &SqliteConnection, db_version: DbVersion) {
         let version = connection
             .fetch_first(GetDatabaseVersionQuery::get_application_version(
@@ -243,7 +249,7 @@ mod tests {
         let (_filepath, connection) =
             create_sqlite_file("test_upgrade_with_migration.sqlite3").unwrap();
         let mut db_checker = DatabaseVersionChecker::new(
-            slog_scope::logger(),
+            discard_logger(),
             ApplicationNodeType::Aggregator,
             &connection,
         );
@@ -302,7 +308,7 @@ mod tests {
     fn starting_with_migration() {
         let (_filepath, connection) = create_sqlite_file("starting_with_migration").unwrap();
         let mut db_checker = DatabaseVersionChecker::new(
-            slog_scope::logger(),
+            discard_logger(),
             ApplicationNodeType::Aggregator,
             &connection,
         );
@@ -325,7 +331,7 @@ mod tests {
     fn test_failing_migration() {
         let (_filepath, connection) = create_sqlite_file("test_failing_migration").unwrap();
         let mut db_checker = DatabaseVersionChecker::new(
-            slog_scope::logger(),
+            discard_logger(),
             ApplicationNodeType::Aggregator,
             &connection,
         );
@@ -356,7 +362,7 @@ mod tests {
     fn test_fail_downgrading() {
         let (_filepath, connection) = create_sqlite_file("test_fail_downgrading").unwrap();
         let mut db_checker = DatabaseVersionChecker::new(
-            slog_scope::logger(),
+            discard_logger(),
             ApplicationNodeType::Aggregator,
             &connection,
         );
@@ -371,7 +377,7 @@ mod tests {
 
         // re instantiate a new checker with no migration registered (version 0).
         let db_checker = DatabaseVersionChecker::new(
-            slog_scope::logger(),
+            discard_logger(),
             ApplicationNodeType::Aggregator,
             &connection,
         );

internal/mithril-persistence/src/database/version_checker.rs

@@ -1,5 +1,6 @@
 use slog::{debug, Logger};
 
+use mithril_common::logging::LoggerExtensions;
 use mithril_common::StdResult;
 
 use crate::sqlite::SqliteConnection;
@@ -24,9 +25,9 @@ impl SqliteCleaningTask {
     /// Get the log message for the task.
     pub fn log_message(self: SqliteCleaningTask) -> &'static str {
         match self {
-            SqliteCleaningTask::Vacuum => "SqliteCleaner::Running `vacuum` on the database",
+            SqliteCleaningTask::Vacuum => "Running `vacuum` on the SQLite database",
             SqliteCleaningTask::WalCheckpointTruncate => {
-                "SqliteCleaner::Running `wal_checkpoint(TRUNCATE)` on the database"
+                "Running `wal_checkpoint(TRUNCATE)` on the SQLite database"
             }
         }
     }
@@ -52,7 +53,7 @@ impl<'a> SqliteCleaner<'a> {
 
     /// Set the logger to be used by the cleaner.
     pub fn with_logger(mut self, logger: Logger) -> Self {
-        self.logger = logger;
+        self.logger = logger.new_with_component_name::<Self>();
         self
     }
 

internal/mithril-persistence/src/sqlite/cleaner.rs

@@ -2,9 +2,10 @@ use std::ops::Not;
 use std::path::{Path, PathBuf};
 
 use anyhow::Context;
-use slog::Logger;
+use slog::{debug, Logger};
 use sqlite::{Connection, ConnectionThreadSafe};
 
+use mithril_common::logging::LoggerExtensions;
 use mithril_common::StdResult;
 
 use crate::database::{ApplicationNodeType, DatabaseVersionChecker, SqlMigration};
@@ -15,7 +16,7 @@ pub struct ConnectionBuilder {
     sql_migrations: Vec<SqlMigration>,
     options: Vec<ConnectionOptions>,
     node_type: ApplicationNodeType,
-    logger: Logger,
+    base_logger: Logger,
 }
 
 /// Options to apply to the connection
@@ -41,7 +42,7 @@ impl ConnectionBuilder {
             sql_migrations: vec![],
             options: vec![],
             node_type: ApplicationNodeType::Signer,
-            logger: Logger::root(slog::Discard, slog::o!()),
+            base_logger: Logger::root(slog::Discard, slog::o!()),
         }
     }
 
@@ -66,7 +67,7 @@ impl ConnectionBuilder {
 
     /// Set the logger to log to at build time
     pub fn with_logger(mut self, logger: Logger) -> Self {
-        self.logger = logger;
+        self.base_logger = logger;
         self
     }
 
@@ -78,6 +79,9 @@ impl ConnectionBuilder {
 
     /// Build a connection based on the builder configuration
     pub fn build(self) -> StdResult<ConnectionThreadSafe> {
+        let logger = self.base_logger.new_with_component_name::<Self>();
+
+        debug!(logger, "Opening SQLite connection"; "path" => self.connection_path.display());
         let connection =
             Connection::open_thread_safe(&self.connection_path).with_context(|| {
                 format!(
@@ -90,21 +94,24 @@ impl ConnectionBuilder {
             .options
             .contains(&ConnectionOptions::EnableWriteAheadLog)
         {
+            debug!(logger, "Enabling SQLite Write Ahead Log journal mode");
             connection
                 .execute("pragma journal_mode = wal; pragma synchronous = normal;")
                 .with_context(|| "SQLite initialization: could not enable WAL.")?;
         }
 
         if self.options.contains(&ConnectionOptions::EnableForeignKeys) {
+            debug!(logger, "Enabling SQLite foreign key support");
             connection
                 .execute("pragma foreign_keys=true")
                 .with_context(|| "SQLite initialization: could not enable FOREIGN KEY support.")?;
         }
 
         if self.sql_migrations.is_empty().not() {
             // Check database migrations
+            debug!(logger, "Applying database migrations");
             let mut db_checker =
-                DatabaseVersionChecker::new(self.logger, self.node_type, &connection);
+                DatabaseVersionChecker::new(self.base_logger, self.node_type, &connection);
 
             for migration in self.sql_migrations {
                 db_checker.add_migration(migration);
@@ -119,6 +126,7 @@ impl ConnectionBuilder {
             .options
             .contains(&ConnectionOptions::ForceDisableForeignKeys)
         {
+            debug!(logger, "Force disabling SQLite foreign key support");
             connection
                 .execute("pragma foreign_keys=false")
                 .with_context(|| "SQLite initialization: could not disable FOREIGN KEY support.")?;

internal/mithril-persistence/src/sqlite/connection_builder.rs

@@ -1,6 +1,6 @@
 [package]
 name = "mithril-signer"
-version = "0.2.195"
+version = "0.2.196"
 description = "A Mithril Signer"
 authors = { workspace = true }
 edition = { workspace = true }
@@ -38,7 +38,6 @@ slog = { version = "2.7.0", features = [
 ] }
 slog-async = "2.8.0"
 slog-bunyan = "2.5.0"
-slog-scope = "4.4.0"
 sqlite = { version = "0.36.1", features = ["bundled"] }
 thiserror = "1.0.63"
 tokio = { version = "1.40.0", features = ["full"] }
@@ -48,10 +47,12 @@ tikv-jemallocator = { version = "0.6.0", optional = true }
 
 [dev-dependencies]
 criterion = { version = "0.5.1", features = ["html_reports", "async_tokio"] }
+http = "1.1.0"
 httpmock = "0.7.0"
 mithril-common = { path = "../mithril-common" }
 mockall = "0.13.0"
 prometheus-parse = "0.2.5"
+slog-scope = "4.4.0"
 slog-term = "2.9.1"
 
 [features]