feat: refactor logging to use tracing crate and make it dynamic (#187)

Cargo.toml

@@ -14,7 +14,6 @@ publish = false # We don't want to publish our binaries.
 zksync_basic_types = { git = "https://github.com/matter-labs/zksync-era.git", rev = "691a7008f6d1f88fb9a5b6b8d92592e1199f37ea" }
 zksync_core = { git = "https://github.com/matter-labs/zksync-era.git", rev = "691a7008f6d1f88fb9a5b6b8d92592e1199f37ea" }
 vm = { git = "https://github.com/matter-labs/zksync-era.git", rev = "691a7008f6d1f88fb9a5b6b8d92592e1199f37ea" }
-vlog = { git = "https://github.com/matter-labs/zksync-era.git", rev = "691a7008f6d1f88fb9a5b6b8d92592e1199f37ea" }
 zksync_contracts = { git = "https://github.com/matter-labs/zksync-era.git", rev = "691a7008f6d1f88fb9a5b6b8d92592e1199f37ea" }
 zksync_types = { git = "https://github.com/matter-labs/zksync-era.git", rev = "691a7008f6d1f88fb9a5b6b8d92592e1199f37ea" }
 zksync_utils = { git = "https://github.com/matter-labs/zksync-era.git", rev = "691a7008f6d1f88fb9a5b6b8d92592e1199f37ea" }
@@ -48,8 +47,6 @@ bigdecimal = { version = "0.2.0" }
 hex = "0.4"
 ethabi = "16.0.0"
 itertools = "0.10.5"
-log = "0.4.20"
-simplelog = "0.12.1"
 rustc-hash = "1.1.0"
 indexmap = "2.0.1"
 chrono = { version = "0.4.31", default-features = false }

README.md

@@ -86,6 +86,8 @@ Additionally, the file path can be provided via the `--log-file-path` option (de
 era_test_node --log=error --log-file-path=run.log run
 ```
 
+The logging can be configured during runtime via the [`config_setLogLevel`](./SUPPORTED_APIS.md#config_setloglevel) and [`config_setLogging`](./SUPPORTED_APIS.md#config_setlogging) methods.
+
 ## 📃 Caching
 
 The node will cache certain network request by default to disk in the `.cache` directory. Alternatively the caching can be disabled or set to in-memory only

SUPPORTED_APIS.md

@@ -21,6 +21,8 @@ The `status` options are:
 | [`CONFIG`](#config-namespace) | [`config_setShowStorageLogs`](#config_setshowstoragelogs) | `SUPPORTED` | Updates `show_storage_logs` to print storage log reads/writes |
 | [`CONFIG`](#config-namespace) | [`config_setShowVmDetails`](#config_setshowvmdetails) | `SUPPORTED` | Updates `show_vm_details` to print more detailed results from vm execution |
 | [`CONFIG`](#config-namespace) | [`config_setShowGasDetails`](#config_setshowgasdetails) | `SUPPORTED` | Updates `show_gas_details` to print more details about gas estimation and usage |
+| [`CONFIG`](#config-namespace) | [`config_setLogLevel`](#config_setloglevel) | `SUPPORTED` | Sets the logging level for the node and only displays the node logs. |
+| [`CONFIG`](#config-namespace) | [`config_setLogging`](#config_setlogging) | `SUPPORTED` | Sets the fine-tuned logging levels for the node and any of its dependencies |
 | [`DEBUG`](#debug-namespace) | [`debug_traceCall`](#debug_tracecall) | `SUPPORTED` | Performs a call and returns structured traces of the execution |
 | [`DEBUG`](#debug-namespace) | [`debug_traceBlockByHash`](#debug_traceblockbyhash) | `SUPPORTED` | Returns structured traces for operations within the block of the specified block hash |
 | [`DEBUG`](#debug-namespace) | [`debug_traceBlockByNumber`](#debug_traceblockbynumber) | `SUPPORTED` | Returns structured traces for operations within the block of the specified block number |
@@ -291,6 +293,53 @@ curl --request POST \
   --data '{"jsonrpc": "2.0","id": "1","method": "config_setResolveHashes","params": [true]}'
 ```
 
+### `config_setLogLevel`
+
+[source](src/configuration_api.rs)
+
+Sets the logging level for the node and only displays the node logs.
+
+#### Arguments
+
++ `level: LogLevel ('trace', 'debug', 'info', 'warn', 'error')`
+
+#### Status
+
+`SUPPORTED`
+
+#### Example
+
+```bash
+curl --request POST \
+  --url http://localhost:8011/ \
+  --header 'content-type: application/json' \
+  --data '{"jsonrpc": "2.0","id": "1","method": "config_setLogLevel","params": ["trace"]}'
+```
+
+### `config_setLogging`
+
+[source](src/configuration_api.rs)
+
+Sets the fine-tuned logging levels for the node and any of its dependencies. 
+The directive format is comma-separated `module=level` for any number of modules.
+
+#### Arguments
+
++ `directive: String (module=level,other_module=level)`
+
+#### Status
+
+`SUPPORTED`
+
+#### Example
+
+```bash
+curl --request POST \
+  --url http://localhost:8011/ \
+  --header 'content-type: application/json' \
+  --data '{"jsonrpc": "2.0","id": "1","method": "config_setLogging","params": ["era_test_node=trace,hyper=debug"]}'
+```
+
 ## `DEBUG NAMESPACE`
 
 ### `debug_traceCall`

src/cache.rs

@@ -70,16 +70,17 @@ impl Cache {
                     CACHE_TYPE_KEY_VALUE,
                 ] {
                     fs::remove_dir_all(Path::new(dir).join(cache_type)).unwrap_or_else(|err| {
-                        log::warn!(
+                        tracing::warn!(
                             "failed removing directory {:?}: {:?}",
                             Path::new(dir).join(cache_type),
                             err
                         )
                     });
                 }
 
-                fs::remove_dir(Path::new(dir))
-                    .unwrap_or_else(|err| log::warn!("failed removing cache directory: {:?}", err));
+                fs::remove_dir(Path::new(dir)).unwrap_or_else(|err| {
+                    tracing::warn!("failed removing cache directory: {:?}", err)
+                });
             }
 
             for cache_type in [
@@ -95,7 +96,7 @@ impl Cache {
             }
             cache
                 .read_all_from_disk(dir)
-                .unwrap_or_else(|err| log::error!("failed reading cache from disk: {:?}", err));
+                .unwrap_or_else(|err| tracing::error!("failed reading cache from disk: {:?}", err));
         }
 
         cache
@@ -313,15 +314,15 @@ impl Cache {
         if let CacheConfig::Disk { dir, .. } = &self.config {
             let file = Path::new(&dir).join(cache_type).join(key);
 
-            log::debug!("writing cache {:?}", file);
+            tracing::debug!("writing cache {:?}", file);
             match File::create(file.clone()) {
                 Ok(cache_file) => {
                     let writer = BufWriter::new(cache_file);
                     if let Err(err) = serde_json::to_writer(writer, data) {
-                        log::error!("failed writing to cache '{:?}': {:?}", file, err);
+                        tracing::error!("failed writing to cache '{:?}': {:?}", file, err);
                     }
                 }
-                Err(err) => log::error!("failed creating file: '{:?}': {:?}", file, err),
+                Err(err) => tracing::error!("failed creating file: '{:?}': {:?}", file, err),
             }
         }
     }

src/configuration_api.rs

@@ -4,6 +4,8 @@ use std::sync::{Arc, RwLock};
 // External uses
 use jsonrpc_core::Result;
 use jsonrpc_derive::rpc;
+use zksync_core::api_server::web3::backend_jsonrpc::error::into_jsrpc_error;
+use zksync_web3_decl::error::Web3Error;
 
 // Workspace uses
 
@@ -13,6 +15,7 @@ use crate::{
     node::ShowCalls,
     node::ShowVMDetails,
     node::{ShowGasDetails, ShowStorageLogs},
+    observability::LogLevel,
 };
 
 pub struct ConfigurationApiNamespace<S> {
@@ -90,6 +93,29 @@ pub trait ConfigurationApiNamespaceT {
     /// The updated `resolve_hashes` value for the InMemoryNodeInner.
     #[rpc(name = "config_setResolveHashes", returns = "bool")]
     fn config_set_resolve_hashes(&self, value: bool) -> Result<bool>;
+
+    /// Set the logging for the InMemoryNodeInner
+    ///
+    /// # Parameters
+    /// - `level`: The log level to set. One of: ["trace", "debug", "info", "warn", "error"]
+    ///
+    /// # Returns
+    /// `true` if the operation succeeded, `false` otherwise.
+    #[rpc(name = "config_setLogLevel", returns = "bool")]
+    fn config_set_log_level(&self, level: LogLevel) -> Result<bool>;
+
+    /// Set the logging for the InMemoryNodeInner
+    ///
+    /// # Parameters
+    /// - `level`: The logging directive to set. Example:
+    ///     * "my_crate=debug"
+    ///     * "my_crate::module=trace"
+    ///     * "my_crate=debug,other_crate=warn"
+    ///
+    /// # Returns
+    /// `true` if the operation succeeded, `false` otherwise.
+    #[rpc(name = "config_setLogging", returns = "bool")]
+    fn config_set_logging(&self, directive: String) -> Result<bool>;
 }
 
 impl<S: std::marker::Send + std::marker::Sync + 'static> ConfigurationApiNamespaceT
@@ -166,4 +192,40 @@ impl<S: std::marker::Send + std::marker::Sync + 'static> ConfigurationApiNamespa
         inner.resolve_hashes = value;
         Ok(inner.resolve_hashes)
     }
+
+    fn config_set_log_level(&self, level: LogLevel) -> Result<bool> {
+        if let Some(observability) = &self
+            .node
+            .read()
+            .map_err(|_| into_jsrpc_error(Web3Error::InternalError))?
+            .observability
+        {
+            match observability.set_log_level(level.clone()) {
+                Ok(_) => tracing::info!("set log level to '{}'", level),
+                Err(err) => {
+                    tracing::error!("failed setting log level {:?}", err);
+                    return Ok(false);
+                }
+            }
+        }
+        Ok(true)
+    }
+
+    fn config_set_logging(&self, directive: String) -> Result<bool> {
+        if let Some(observability) = &self
+            .node
+            .read()
+            .map_err(|_| into_jsrpc_error(Web3Error::InternalError))?
+            .observability
+        {
+            match observability.set_logging(&directive) {
+                Ok(_) => tracing::info!("set logging to '{}'", directive),
+                Err(err) => {
+                    tracing::error!("failed setting logging to '{}': {:?}", directive, err);
+                    return Ok(false);
+                }
+            }
+        }
+        Ok(true)
+    }
 }

src/console_log.rs

@@ -59,7 +59,7 @@ impl ConsoleLogHandler {
                         tokens.iter().map(|t| format!("{}", t)).join(" ")
                     })
                 });
-        log::info!("{}", message.cyan());
+        tracing::info!("{}", message.cyan());
     }
 }
 

src/evm.rs

@@ -161,7 +161,7 @@ impl<S: Send + Sync + 'static + ForkSource + std::fmt::Debug> EvmNamespaceT
             match inner.write() {
                 Ok(mut inner) => {
                     mine_empty_blocks(&mut inner, 1, 1000);
-                    log::info!("👷 Mined block #{}", inner.current_miniblock);
+                    tracing::info!("👷 Mined block #{}", inner.current_miniblock);
                     Ok("0x0".to_string())
                 }
                 Err(_) => Err(into_jsrpc_error(Web3Error::InternalError)),
@@ -178,12 +178,12 @@ impl<S: Send + Sync + 'static + ForkSource + std::fmt::Debug> EvmNamespaceT
             snapshots
                 .read()
                 .map_err(|err| {
-                    log::error!("failed acquiring read lock for snapshot: {:?}", err);
+                    tracing::error!("failed acquiring read lock for snapshot: {:?}", err);
                     into_jsrpc_error(Web3Error::InternalError)
                 })
                 .and_then(|snapshots| {
                     if snapshots.len() >= MAX_SNAPSHOTS as usize {
-                        log::error!("maximum number of '{}' snapshots exceeded", MAX_SNAPSHOTS);
+                        tracing::error!("maximum number of '{}' snapshots exceeded", MAX_SNAPSHOTS);
                         Err(into_jsrpc_error(Web3Error::InternalError))
                     } else {
                         Ok(())
@@ -198,18 +198,18 @@ impl<S: Send + Sync + 'static + ForkSource + std::fmt::Debug> EvmNamespaceT
                 })
                 .and_then(|reader| reader.snapshot())
                 .map_err(|err| {
-                    log::error!("failed creating snapshot: {:?}", err);
+                    tracing::error!("failed creating snapshot: {:?}", err);
                     into_jsrpc_error(Web3Error::InternalError)
                 })?;
             snapshots
                 .write()
                 .map(|mut snapshots| {
                     snapshots.push(snapshot);
-                    log::info!("Created snapshot '{}'", snapshots.len());
+                    tracing::info!("Created snapshot '{}'", snapshots.len());
                     snapshots.len()
                 })
                 .map_err(|err| {
-                    log::error!("failed storing snapshot: {:?}", err);
+                    tracing::error!("failed storing snapshot: {:?}", err);
                     into_jsrpc_error(Web3Error::InternalError)
                 })
                 .map(U64::from)
@@ -222,12 +222,12 @@ impl<S: Send + Sync + 'static + ForkSource + std::fmt::Debug> EvmNamespaceT
 
         Box::pin(async move {
             let mut snapshots = snapshots.write().map_err(|err| {
-                log::error!("failed acquiring read lock for snapshots: {:?}", err);
+                tracing::error!("failed acquiring read lock for snapshots: {:?}", err);
                 into_jsrpc_error(Web3Error::InternalError)
             })?;
             let snapshot_id_index = snapshot_id.as_usize().saturating_sub(1);
             if snapshot_id_index >= snapshots.len() {
-                log::error!("no snapshot exists for the id '{}'", snapshot_id);
+                tracing::error!("no snapshot exists for the id '{}'", snapshot_id);
                 return Err(into_jsrpc_error(Web3Error::InternalError));
             }
 
@@ -241,11 +241,11 @@ impl<S: Send + Sync + 'static + ForkSource + std::fmt::Debug> EvmNamespaceT
                 .write()
                 .map_err(|err| format!("failed acquiring read lock for snapshots: {:?}", err))
                 .and_then(|mut writer| {
-                    log::info!("Reverting node to snapshot '{snapshot_id:?}'");
+                    tracing::info!("Reverting node to snapshot '{snapshot_id:?}'");
                     writer.restore_snapshot(selected_snapshot).map(|_| true)
                 })
                 .or_else(|err| {
-                    log::error!(
+                    tracing::error!(
                         "failed restoring snapshot for id '{}': {}",
                         snapshot_id,
                         err