feat: logger (#186)

* feat: add dependencies

* feat: implement logger

* feat: add build info

* feat: use logger in hermes main

* fix: update logger to support only

* fix: main log

* fix: log error in ClockState

* doc: add logger doc

* fix: formatter

* style: disable exit linter error

* feat: add tracing to log level

* fix: make bool param

* fix: clean up main

* fix: get env log level

* feat: add serde json

* feat: hermes api logger

* feat: add logger to lib

* fix: add entry

* fix: refactor log api

* fix: remove serde json

* fix: clean up

* fix: add context span

* fix: implementt new logging api

* fix: fomat

* fix: remove level from api

* fix: linter

* fix: structure and format

* fix: typo

* feat: add derive more

* fix: cleanup

* fix: enable feat cargo toml

* fix: comment out reactor wait

* fix: add default feat for derive more

* fix: cleanup

* fix: syntax

* fix: cargo toml

* fix: cleanup and implement logger builder

* fix: move build info log

* fix: formatter

* Update hermes/bin/src/main.rs

Co-authored-by: Felipe Rosa <[email protected]>

---------

Co-authored-by: Alex Pozhylenkov <[email protected]>
Co-authored-by: Felipe Rosa <[email protected]>

hermes/Cargo.toml

@@ -77,3 +77,7 @@ bip32 = "0.5.1"
 ed25519-bip32 = "0.4.1"
 dashmap = "5.5.3"
 once_cell = "1.19.0"
+clap = "4.5.3"
+build-info = "0.0.36"
+derive_more = { version= "0.99.17", default-features= false }
+build-info-build = "0.0.36"

hermes/bin/Cargo.toml

@@ -41,8 +41,17 @@ bip32 = { workspace = true }
 ed25519-bip32 = { workspace = true }
 dashmap = { workspace = true }
 once_cell = { workspace = true }
+clap = { workspace = true, features = ["derive", "env"] }
+tracing = { workspace = true, features = ["log"] }
+tracing-subscriber = { workspace = true, features = ["fmt", "json", "time"] }
+build-info = { workspace = true }
+derive_more = { workspace = true, features = ["display"], default-features = false }
 
 [[test]]
 name = "wasm-component-integration-tests"
 path = "tests/wasm-integration/main.rs"
 harness = false
+
+[build-dependencies]
+
+build-info-build = { workspace = true }

hermes/bin/build.rs

@@ -0,0 +1,4 @@
+//! Build
+fn main() {
+    build_info_build::build_script();
+}

hermes/bin/src/lib.rs

@@ -3,6 +3,7 @@
 
 pub mod app;
 pub mod event;
+pub mod logger;
 pub mod reactor;
 pub mod runtime_context;
 pub mod runtime_extensions;

hermes/bin/src/logger.rs

@@ -0,0 +1,171 @@
+//! Setup for logging for the service.
+
+use std::str::FromStr;
+
+use clap::ValueEnum;
+extern crate derive_more;
+use derive_more::Display;
+use tracing::{level_filters::LevelFilter, subscriber::SetGlobalDefaultError};
+use tracing_subscriber::{
+    fmt::{format::FmtSpan, time},
+    FmtSubscriber,
+};
+
+use crate::runtime_extensions::bindings::hermes::logging::api::Level;
+
+/// All valid logging levels.
+#[derive(ValueEnum, Clone, Copy, Display, Default)]
+pub(crate) enum LogLevel {
+    /// Errors
+    #[display(fmt = "Error")]
+    Error,
+    /// Warnings
+    #[display(fmt = "Warn")]
+    Warn,
+    /// Informational Messages
+    #[display(fmt = "Info")]
+    #[default]
+    Info,
+    /// Debug messages
+    #[display(fmt = "Debug")]
+    Debug,
+    /// Tracing
+    #[display(fmt = "Trace")]
+    Trace,
+}
+
+impl FromStr for LogLevel {
+    type Err = ();
+
+    fn from_str(s: &str) -> Result<Self, Self::Err> {
+        // Error and Warn levels are force to Info level
+        // as Info is the highest log level one can choose.
+        match s {
+            "error" | "warn" | "info" => Ok(LogLevel::Info),
+            "debug" => Ok(LogLevel::Debug),
+            "trace" => Ok(LogLevel::Trace),
+            _ => Err(()),
+        }
+    }
+}
+
+impl From<Level> for LogLevel {
+    fn from(level: Level) -> Self {
+        // Error and Warn levels are force to Info level
+        // as Info is the highest log level one can choose.
+        match level {
+            Level::Info | Level::Warn | Level::Error => LogLevel::Info,
+            Level::Debug => LogLevel::Debug,
+            Level::Trace => LogLevel::Trace,
+        }
+    }
+}
+
+/// Implements a conversion from `LogLevel` enum to the `tracing::Level`.
+impl From<LogLevel> for tracing::Level {
+    fn from(val: LogLevel) -> Self {
+        match val {
+            LogLevel::Error => Self::ERROR,
+            LogLevel::Warn => Self::WARN,
+            LogLevel::Info => Self::INFO,
+            LogLevel::Debug => Self::DEBUG,
+            LogLevel::Trace => Self::TRACE,
+        }
+    }
+}
+
+/// Logger configuration.
+#[derive(Default)]
+pub(crate) struct LoggerConfig {
+    /// Log level.
+    log_level: LogLevel,
+    /// Enable/disable thread logging.
+    with_thread: bool,
+    /// Enable/disable file logging.
+    with_file: bool,
+    /// Enable/disable line number logging.
+    with_line_num: bool,
+}
+
+#[allow(dead_code)]
+impl LoggerConfig {
+    /// Entry point to logger building.
+    pub(crate) fn builder() -> LoggerConfigBuilder {
+        LoggerConfigBuilder::default()
+    }
+}
+
+/// Logger configuration builder.
+#[derive(Default)]
+pub(crate) struct LoggerConfigBuilder {
+    /// Builder log level.
+    log_level: Option<LogLevel>,
+    /// Builder enable/disable thread logging.
+    with_thread: Option<bool>,
+    /// Builder enable/disable file logging.
+    with_file: Option<bool>,
+    /// Builder enable/disable line number logging.
+    with_line_num: Option<bool>,
+}
+
+#[allow(dead_code)]
+impl LoggerConfigBuilder {
+    /// Build the logger configuration.
+    pub(crate) fn build(self) -> LoggerConfig {
+        LoggerConfig {
+            log_level: self.log_level.unwrap_or(LogLevel::Info),
+            with_thread: self.with_thread.unwrap_or(false),
+            with_file: self.with_file.unwrap_or(false),
+            with_line_num: self.with_line_num.unwrap_or(false),
+        }
+    }
+
+    /// Set log level.
+    pub(crate) fn log_level(mut self, level: LogLevel) -> Self {
+        self.log_level = Some(level);
+        self
+    }
+
+    /// Enable/disable thread logging.
+    pub(crate) fn with_thread(mut self, enable: bool) -> Self {
+        self.with_thread = Some(enable);
+        self
+    }
+
+    /// Enable/disable file logging.
+    pub(crate) fn with_file(mut self, enable: bool) -> Self {
+        self.with_file = Some(enable);
+        self
+    }
+
+    /// Enable/disable line number logging.
+    pub(crate) fn with_line_num(mut self, enable: bool) -> Self {
+        self.with_line_num = Some(enable);
+        self
+    }
+}
+
+/// Initializes the subscriber for the logger with the following features.
+/// - JSON format
+/// - Display event level
+/// - Display thread names and ids
+/// - Display event's source code file path and line number
+/// - Display time in RFC 3339 format
+/// - Events emit when the span close
+/// - Maximum verbosity level
+#[allow(dead_code)]
+pub(crate) fn init(logger_config: &LoggerConfig) -> Result<(), SetGlobalDefaultError> {
+    let subscriber = FmtSubscriber::builder()
+        .json()
+        .with_level(true)
+        .with_thread_names(logger_config.with_thread)
+        .with_thread_ids(logger_config.with_thread)
+        .with_file(logger_config.with_file)
+        .with_line_number(logger_config.with_line_num)
+        .with_timer(time::UtcTime::rfc_3339())
+        .with_span_events(FmtSpan::CLOSE)
+        .with_max_level(LevelFilter::from_level(logger_config.log_level.into()))
+        .finish();
+
+    tracing::subscriber::set_global_default(subscriber)
+}

hermes/bin/src/main.rs

@@ -2,17 +2,63 @@
 
 mod app;
 mod event;
+mod logger;
 mod reactor;
 mod runtime_context;
 mod runtime_extensions;
 mod wasm;
 
+use std::{env, process, str::FromStr};
+
+use tracing::{error, info};
 #[cfg(feature = "bench")]
 pub use wasm::module::bench::{
     module_hermes_component_bench, module_small_component_bench,
     module_small_component_full_pre_load_bench,
 };
 
+use crate::logger::{LogLevel, LoggerConfig};
+
+build_info::build_info!(fn build_info);
+
+/// A parameter identifier specifying the log level.
+const ENV_LOG_LEVEL: &str = "HERMES_LOG_LEVEL";
+/// The default value for the log level when not specified.
+const DEFAULT_ENV_LOG_LEVEL: &str = "info";
+
+// Disable process exit for clippy.
+#[allow(clippy::exit)]
 fn main() {
-    println!("Hello, world!");
+    let log_level = env::var(ENV_LOG_LEVEL).unwrap_or_else(|_| DEFAULT_ENV_LOG_LEVEL.to_owned());
+
+    let config = LoggerConfig::builder()
+        .log_level(LogLevel::from_str(&log_level).unwrap_or_default())
+        .with_thread(true)
+        .with_file(true)
+        .with_line_num(true)
+        .build();
+
+    // Initialize logger.
+    if let Err(err) = logger::init(&config) {
+        println!("Error initializing logger: {err}");
+    }
+    // Get build info string.
+    let build_info_str = format!("{:?}", build_info());
+
+    info!("{}", build_info_str);
+
+    // Create a new reactor instance.
+    let reactor_result = reactor::HermesReactor::new(Vec::new());
+    let mut _reactor = match reactor_result {
+        Ok(reactor) => reactor,
+        Err(err) => {
+            error!("Error creating reactor: {}", err);
+            process::exit(1);
+        },
+    };
+    // Comment out, since it causes CI to run forever.
+    // if let Err(err) = reactor.wait() {
+    //     error!("Error in reactor: {}", err);
+    //     process::exit(1);
+    // }
 }

hermes/bin/src/runtime_extensions/hermes/logging/host.rs

@@ -1,6 +1,8 @@
 //! Logging host implementation for WASM runtime.
 
+use super::log_msg::log_message;
 use crate::{
+    logger::LogLevel,
     runtime_context::HermesRuntimeContext,
     runtime_extensions::bindings::hermes::{
         json::api::Json,
@@ -24,7 +26,7 @@ impl Host for HermesRuntimeContext {
     ///
     /// - `level` : The log level this message is for.
     /// - `file`  : The name of the src file being logged from. (Optional)
-    /// - `fn`    : The function within the file being logged from. (Optional)
+    /// - `function`    : The function within the file being logged from. (Optional)
     /// - `line`  : The line of code the log was generated from. (Optional)
     /// - `col`   : The column of code the log was generated from. (Optional)
     /// - `ctx`   : The logging context.  (Should have no newlines or formatting).
@@ -55,9 +57,19 @@ impl Host for HermesRuntimeContext {
     /// Backtrace must be contained in a single `log` call.  Multiple log calls will be
     /// considered independent logs.
     fn log(
-        &mut self, _level: Level, _file: Option<String>, _fn_: Option<String>, _line: Option<u32>,
-        _col: Option<u32>, _ctx: Option<String>, _msg: String, _data: Option<Json>,
+        &mut self, level: Level, file: Option<String>, function: Option<String>, line: Option<u32>,
+        col: Option<u32>, ctx: Option<String>, msg: String, data: Option<Json>,
     ) -> wasmtime::Result<()> {
-        todo!()
+        log_message(
+            LogLevel::from(level),
+            ctx,
+            &msg,
+            file,
+            function,
+            line,
+            col,
+            data,
+        );
+        Ok(())
     }
 }

hermes/bin/src/runtime_extensions/hermes/logging/log_msg.rs

@@ -0,0 +1,72 @@
+//! Implementation of logging API
+use tracing::info;
+
+use crate::logger::LogLevel;
+
+/// Log a message
+#[allow(clippy::too_many_arguments)]
+pub(crate) fn log_message(
+    level: LogLevel, ctx: Option<String>, msg: &str, file: Option<String>,
+    function: Option<String>, line: Option<u32>, col: Option<u32>, data: Option<String>,
+) {
+    info!(
+        level = level.to_string(),
+        ctx = ctx.unwrap_or_default(),
+        message = msg,
+        file = file.unwrap_or_default(),
+        function = function.unwrap_or_default(),
+        line = line.unwrap_or_default(),
+        column = col.unwrap_or_default(),
+        data = data.unwrap_or_default(),
+    );
+}
+
+#[cfg(test)]
+mod tests_log_msg {
+    use super::*;
+    use crate::{
+        logger::{init, LogLevel, LoggerConfig},
+        runtime_extensions::bindings::hermes::logging::api::Level,
+    };
+
+    #[test]
+    fn test_log_message() {
+        let config = LoggerConfig::default();
+
+        if let Err(err) = init(&config) {
+            println!("Error initializing logger: {err}");
+        }
+
+        // Test with valid data
+        let level = Level::Warn;
+        let ctx = Some("Context".to_string());
+        let msg = "Test message";
+        let file = Some("test.rs".to_string());
+        let function = Some("test_log_message".to_string());
+        let line = Some(10);
+        let col = Some(5);
+        let data = Some("{\"bt\": [\"Array:1\", \"Array:2\", \"Array:3\"]}".to_string());
+
+        log_message(
+            LogLevel::from(level),
+            ctx.clone(),
+            msg,
+            file.clone(),
+            function.clone(),
+            line,
+            col,
+            data.clone(),
+        );
+
+        log_message(
+            LogLevel::from(level),
+            ctx,
+            msg,
+            file,
+            function,
+            line,
+            col,
+            None,
+        );
+    }
+}

hermes/bin/src/runtime_extensions/hermes/logging/mod.rs

@@ -1,6 +1,7 @@
 //! Logging runtime extension implementation.
 
 mod host;
+mod log_msg;
 
 /// Advise Runtime Extensions of a new context
 pub(crate) fn new_context(_ctx: &crate::runtime_context::HermesRuntimeContext) {}