From 1dde85d4b16fb1d450b39538883a27a05a053970 Mon Sep 17 00:00:00 2001 From: Nisheeth Barthwal Date: Thu, 19 Oct 2023 09:31:20 +0200 Subject: [PATCH] feat: refactor logging to use tracing crate and make it dynamic (#187) --- Cargo.lock | 25 -- Cargo.toml | 3 - README.md | 2 + SUPPORTED_APIS.md | 49 ++++ src/cache.rs | 15 +- src/configuration_api.rs | 62 +++++ src/console_log.rs | 2 +- src/evm.rs | 20 +- src/filters.rs | 8 +- src/fork.rs | 4 +- src/formatter.rs | 42 ++-- src/hardhat.rs | 16 +- src/http_fork_source.rs | 23 +- src/lib.rs | 1 + src/logging_middleware.rs | 10 +- src/main.rs | 101 +++----- src/node.rs | 469 +++++++++++++++++--------------------- src/observability.rs | 126 ++++++++++ src/system_contracts.rs | 2 + src/utils.rs | 2 +- src/zks.rs | 49 +--- test_endpoints.http | 24 +- 22 files changed, 591 insertions(+), 464 deletions(-) create mode 100644 src/observability.rs diff --git a/Cargo.lock b/Cargo.lock index c6b4aa37..4fe36ac3 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2140,7 +2140,6 @@ dependencies = [ "jsonrpc-derive", "jsonrpc-http-server", "lazy_static", - "log", "maplit", "once_cell", "openssl-sys", @@ -2148,12 +2147,10 @@ dependencies = [ "rustc-hash", "serde", "serde_json", - "simplelog", "tempdir", "tokio", "tracing", "tracing-subscriber", - "vlog", "vm", "zksync-web3-rs", "zksync_basic_types", @@ -4756,15 +4753,6 @@ dependencies = [ "syn 2.0.38", ] -[[package]] -name = "num_threads" -version = "0.1.6" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2819ce041d2ee131036f4fc9d6ae7ae125a3a40e97ba64d04fe799ad9dabbb44" -dependencies = [ - "libc", -] - [[package]] name = "object" version = "0.32.1" @@ -6722,17 +6710,6 @@ dependencies = [ "time", ] -[[package]] -name = "simplelog" -version = "0.12.1" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "acee08041c5de3d5048c8b3f6f13fafb3026b24ba43c6a695a0c76179b844369" -dependencies = [ - "log", - "termcolor", - "time", -] - [[package]] name = "siphasher" version = "0.3.11" @@ -7316,8 +7293,6 @@ checksum = "426f806f4089c493dcac0d24c29c01e2c38baf8e30f1b716ee37e83d200b18fe" dependencies = [ "deranged", "itoa", - "libc", - "num_threads", "serde", "time-core", "time-macros", diff --git a/Cargo.toml b/Cargo.toml index 97a7042a..52839f72 100644 --- a/Cargo.toml +++ b/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 } diff --git a/README.md b/README.md index 6a0f61fe..c043c102 100644 --- a/README.md +++ b/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 diff --git a/SUPPORTED_APIS.md b/SUPPORTED_APIS.md index 62397aa2..b1082721 100644 --- a/SUPPORTED_APIS.md +++ b/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` diff --git a/src/cache.rs b/src/cache.rs index 834d7d97..4e9fd2bc 100644 --- a/src/cache.rs +++ b/src/cache.rs @@ -70,7 +70,7 @@ 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 @@ -78,8 +78,9 @@ impl Cache { }); } - 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), } } } diff --git a/src/configuration_api.rs b/src/configuration_api.rs index e5420d7c..868c7b95 100644 --- a/src/configuration_api.rs +++ b/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 { @@ -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; + + /// 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; + + /// 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; } impl ConfigurationApiNamespaceT @@ -166,4 +192,40 @@ impl ConfigurationApiNamespa inner.resolve_hashes = value; Ok(inner.resolve_hashes) } + + fn config_set_log_level(&self, level: LogLevel) -> Result { + 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 { + 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) + } } diff --git a/src/console_log.rs b/src/console_log.rs index 6f24d48f..b6ef9bfc 100644 --- a/src/console_log.rs +++ b/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()); } } diff --git a/src/evm.rs b/src/evm.rs index f1519712..ed3efc78 100644 --- a/src/evm.rs +++ b/src/evm.rs @@ -161,7 +161,7 @@ impl 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 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 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 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 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 diff --git a/src/filters.rs b/src/filters.rs index 79be1840..8d4214dd 100644 --- a/src/filters.rs +++ b/src/filters.rs @@ -107,7 +107,7 @@ impl EthFilters { }), ); - log::info!("created block filter '{:#x}'", self.id_counter); + tracing::info!("created block filter '{:#x}'", self.id_counter); Ok(self.id_counter) } @@ -134,7 +134,7 @@ impl EthFilters { })), ); - log::info!("created log filter '{:#x}'", self.id_counter); + tracing::info!("created log filter '{:#x}'", self.id_counter); Ok(self.id_counter) } @@ -151,7 +151,7 @@ impl EthFilters { }), ); - log::info!( + tracing::info!( "created pending transaction filter '{:#x}'", self.id_counter ); @@ -160,7 +160,7 @@ impl EthFilters { /// Removes the filter with the given id. Returns true if the filter existed, false otherwise. pub fn remove_filter(&mut self, id: U256) -> bool { - log::info!("removing filter '{id:#x}'"); + tracing::info!("removing filter '{id:#x}'"); self.filters.remove(&id).is_some() } diff --git a/src/fork.rs b/src/fork.rs index 884a6df7..f898508c 100644 --- a/src/fork.rs +++ b/src/fork.rs @@ -80,7 +80,7 @@ impl ForkStorage { .as_ref() .and_then(|d| d.overwrite_chain_id) .unwrap_or(L2ChainId::from(TEST_NODE_NETWORK_ID)); - log::info!("Starting network with chain id: {:?}", chain_id); + tracing::info!("Starting network with chain id: {:?}", chain_id); ForkStorage { inner: Arc::new(RwLock::new(ForkStorageInner { @@ -328,7 +328,7 @@ impl ForkDetails { }); let l1_batch_number = block_details.l1_batch_number; - log::info!( + tracing::info!( "Creating fork from {:?} L1 block: {:?} L2 block: {:?} with timestamp {:?}, L1 gas price {:?} and protocol version: {:?}" , url, l1_batch_number, miniblock, block_details.base.timestamp, block_details.base.l1_gas_price, block_details.protocol_version ); diff --git a/src/formatter.rs b/src/formatter.rs index 57cfeacd..080046eb 100644 --- a/src/formatter.rs +++ b/src/formatter.rs @@ -73,7 +73,7 @@ pub fn print_event(event: &VmEvent, resolve_hashes: bool) { } } - log::info!( + tracing::info!( "{} {}", address_to_human_readable(event.address) .map(|x| format!("{:42}", x.blue())) @@ -151,9 +151,9 @@ pub fn print_call(call: &Call, padding: usize, show_calls: &ShowCalls, resolve_h ); if call.revert_reason.as_ref().is_some() || call.error.as_ref().is_some() { - log::info!("{}", pretty_print.on_red()); + tracing::info!("{}", pretty_print.on_red()); } else { - log::info!("{}", pretty_print); + tracing::info!("{}", pretty_print); } } for subcall in &call.calls { @@ -163,48 +163,48 @@ pub fn print_call(call: &Call, padding: usize, show_calls: &ShowCalls, resolve_h pub fn print_logs(log_query: &StorageLogQuery) { let separator = "─".repeat(82); - log::info!("{:<15} {:?}", "Type:", log_query.log_type); - log::info!( + tracing::info!("{:<15} {:?}", "Type:", log_query.log_type); + tracing::info!( "{:<15} {}", "Address:", address_to_human_readable(log_query.log_query.address) .unwrap_or(format!("{}", log_query.log_query.address)) ); - log::info!("{:<15} {:#066x}", "Key:", log_query.log_query.key); + tracing::info!("{:<15} {:#066x}", "Key:", log_query.log_query.key); - log::info!( + tracing::info!( "{:<15} {:#066x}", "Read Value:", log_query.log_query.read_value ); if log_query.log_type != StorageLogQueryType::Read { - log::info!( + tracing::info!( "{:<15} {:#066x}", "Written Value:", log_query.log_query.written_value ); } - log::info!("{}", separator); + tracing::info!("{}", separator); } pub fn print_vm_details(result: &VmExecutionResultAndLogs) { - log::info!(""); - log::info!("┌──────────────────────────┐"); - log::info!("│ VM EXECUTION RESULTS │"); - log::info!("└──────────────────────────┘"); + tracing::info!(""); + tracing::info!("┌──────────────────────────┐"); + tracing::info!("│ VM EXECUTION RESULTS │"); + tracing::info!("└──────────────────────────┘"); - log::info!("Cycles Used: {}", result.statistics.cycles_used); - log::info!( + tracing::info!("Cycles Used: {}", result.statistics.cycles_used); + tracing::info!( "Computation Gas Used: {}", result.statistics.computational_gas_used ); - log::info!("Contracts Used: {}", result.statistics.contracts_used); + tracing::info!("Contracts Used: {}", result.statistics.contracts_used); match &result.result { vm::ExecutionResult::Success { .. } => {} vm::ExecutionResult::Revert { output } => { - log::info!(""); - log::info!( + tracing::info!(""); + tracing::info!( "{}", format!( "\n[!] Revert Reason: {}", @@ -214,10 +214,10 @@ pub fn print_vm_details(result: &VmExecutionResultAndLogs) { ); } vm::ExecutionResult::Halt { reason } => { - log::info!(""); - log::info!("{}", format!("\n[!] Halt Reason: {}", reason).on_red()); + tracing::info!(""); + tracing::info!("{}", format!("\n[!] Halt Reason: {}", reason).on_red()); } } - log::info!("════════════════════════════"); + tracing::info!("════════════════════════════"); } diff --git a/src/hardhat.rs b/src/hardhat.rs index 762a1d29..dc99774e 100644 --- a/src/hardhat.rs +++ b/src/hardhat.rs @@ -135,7 +135,7 @@ impl HardhatNamespaceT inner_guard .fork_storage .set_value(balance_key, u256_to_h256(balance)); - log::info!( + tracing::info!( "👷 Balance for address {:?} has been manually set to {} Wei", address, balance @@ -178,7 +178,7 @@ impl HardhatNamespaceT } deployment_nonce = nonce; let enforced_full_nonce = nonces_to_full_nonce(account_nonce, deployment_nonce); - log::info!( + tracing::info!( "👷 Nonces for address {:?} have been set to {}", address, nonce @@ -212,7 +212,7 @@ impl HardhatNamespaceT )); } mine_empty_blocks(&mut inner, num_blocks.as_u64(), interval_ms.as_u64()); - log::info!("👷 Mined {} blocks", num_blocks); + tracing::info!("👷 Mined {} blocks", num_blocks); Ok(true) } Err(_) => Err(into_jsrpc_error(Web3Error::InternalError)), @@ -226,10 +226,10 @@ impl HardhatNamespaceT match inner.write() { Ok(mut inner) => { if inner.set_impersonated_account(address) { - log::info!("🕵️ Account {:?} has been impersonated", address); + tracing::info!("🕵️ Account {:?} has been impersonated", address); Ok(true) } else { - log::info!("🕵️ Account {:?} was already impersonated", address); + tracing::info!("🕵️ Account {:?} was already impersonated", address); Ok(false) } } @@ -244,10 +244,10 @@ impl HardhatNamespaceT match inner.write() { Ok(mut inner) => { if inner.stop_impersonating_account(address) { - log::info!("🕵️ Stopped impersonating account {:?}", address); + tracing::info!("🕵️ Stopped impersonating account {:?}", address); Ok(true) } else { - log::info!( + tracing::info!( "🕵️ Account {:?} was not impersonated, nothing to stop", address ); @@ -265,7 +265,7 @@ impl HardhatNamespaceT .write() .map(|mut writer| { let code_key = get_code_key(&address); - log::info!("set code for address {address:#x}"); + tracing::info!("set code for address {address:#x}"); let (hash, code) = bytecode_to_factory_dep(code); let hash = u256_to_h256(hash); writer.fork_storage.store_factory_dep( diff --git a/src/http_fork_source.rs b/src/http_fork_source.rs index df12fe15..c375bd16 100644 --- a/src/http_fork_source.rs +++ b/src/http_fork_source.rs @@ -68,7 +68,7 @@ impl ForkSource for HttpForkSource { .read() .map(|guard| guard.get_transaction(&hash).cloned()) { - log::debug!("using cached transaction for {hash}"); + tracing::debug!("using cached transaction for {hash}"); return Ok(Some(transaction)); } @@ -80,7 +80,7 @@ impl ForkSource for HttpForkSource { .write() .map(|mut guard| guard.insert_transaction(hash, transaction.clone())) .unwrap_or_else(|err| { - log::warn!( + tracing::warn!( "failed writing to cache for 'get_transaction_by_hash': {:?}", err ) @@ -113,7 +113,7 @@ impl ForkSource for HttpForkSource { .read() .map(|guard| guard.get_block_raw_transactions(&number).cloned()) { - log::debug!("using cached raw transactions for block {block_number}"); + tracing::debug!("using cached raw transactions for block {block_number}"); return Ok(transaction); } @@ -128,7 +128,7 @@ impl ForkSource for HttpForkSource { guard.insert_block_raw_transactions(number, transactions.clone()) }) .unwrap_or_else(|err| { - log::warn!( + tracing::warn!( "failed writing to cache for 'get_raw_block_transactions': {:?}", err ) @@ -148,7 +148,7 @@ impl ForkSource for HttpForkSource { .read() .map(|guard| guard.get_block(&hash, full_transactions).cloned()) { - log::debug!("using cached block for {hash}"); + tracing::debug!("using cached block for {hash}"); return Ok(Some(block)); } @@ -160,7 +160,10 @@ impl ForkSource for HttpForkSource { .write() .map(|mut guard| guard.insert_block(hash, full_transactions, block.clone())) .unwrap_or_else(|err| { - log::warn!("failed writing to cache for 'get_block_by_hash': {:?}", err) + tracing::warn!( + "failed writing to cache for 'get_block_by_hash': {:?}", + err + ) }); } block @@ -185,7 +188,7 @@ impl ForkSource for HttpForkSource { .and_then(|hash| guard.get_block(hash, full_transactions).cloned()) }) }) { - log::debug!("using cached block for {block_number}"); + tracing::debug!("using cached block for {block_number}"); return Ok(Some(block)); } @@ -203,7 +206,7 @@ impl ForkSource for HttpForkSource { guard.insert_block(block.hash, full_transactions, block.clone()) }) .unwrap_or_else(|err| { - log::warn!( + tracing::warn!( "failed writing to cache for 'get_block_by_number': {:?}", err ) @@ -283,7 +286,7 @@ impl ForkSource for HttpForkSource { .ok() .and_then(|guard| guard.get_bridge_addresses().cloned()) { - log::debug!("using cached bridge contracts"); + tracing::debug!("using cached bridge contracts"); return Ok(bridge_addresses); }; @@ -294,7 +297,7 @@ impl ForkSource for HttpForkSource { .write() .map(|mut guard| guard.set_bridge_addresses(bridge_addresses.clone())) .unwrap_or_else(|err| { - log::warn!( + tracing::warn!( "failed writing to cache for 'get_bridge_contracts': {:?}", err ) diff --git a/src/lib.rs b/src/lib.rs index 5c3c410a..f92e7c7c 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -50,6 +50,7 @@ pub mod fork; pub mod formatter; pub mod http_fork_source; pub mod node; +pub mod observability; pub mod resolver; pub mod system_contracts; pub mod utils; diff --git a/src/logging_middleware.rs b/src/logging_middleware.rs index 41255a25..1efde748 100644 --- a/src/logging_middleware.rs +++ b/src/logging_middleware.rs @@ -5,7 +5,7 @@ use itertools::Itertools; use jsonrpc_core::{ middleware, Call, FutureResponse, Metadata, Middleware, Params, Request, Response, }; -use log::LevelFilter; +use tracing_subscriber::filter::LevelFilter; #[derive(Clone, Debug, Default)] pub struct Meta(); @@ -35,7 +35,7 @@ impl Middleware for LoggingMiddleware { { if let Request::Single(Call::MethodCall(method_call)) = &request { match self.log_level_filter { - LevelFilter::Trace => { + LevelFilter::TRACE => { let full_params = match &method_call.params { Params::Array(values) => { if values.is_empty() { @@ -47,7 +47,7 @@ impl Middleware for LoggingMiddleware { _ => String::default(), }; - log::trace!("{} was called {}", method_call.method.cyan(), full_params); + tracing::trace!("{} was called {}", method_call.method.cyan(), full_params); } _ => { // Generate truncated params for requests with massive payloads @@ -76,7 +76,7 @@ impl Middleware for LoggingMiddleware { _ => String::default(), }; - log::debug!( + tracing::debug!( "{} was called {}", method_call.method.cyan(), truncated_params @@ -86,7 +86,7 @@ impl Middleware for LoggingMiddleware { }; Either::Left(Box::pin(next(request, meta).map(move |res| { - log::trace!("API response => {:?}", res); + tracing::trace!("API response => {:?}", res); res }))) } diff --git a/src/main.rs b/src/main.rs index 96b1defe..e23bc6f8 100644 --- a/src/main.rs +++ b/src/main.rs @@ -1,6 +1,7 @@ use crate::cache::CacheConfig; use crate::hardhat::{HardhatNamespaceImpl, HardhatNamespaceT}; -use crate::node::{ShowGasDetails, ShowStorageLogs, ShowVMDetails}; +use crate::node::{InMemoryNodeConfig, ShowGasDetails, ShowStorageLogs, ShowVMDetails}; +use crate::observability::Observability; use clap::{Parser, Subcommand, ValueEnum}; use configuration_api::ConfigurationApiNamespaceT; use debug::DebugNamespaceImpl; @@ -8,9 +9,8 @@ use evm::{EvmNamespaceImpl, EvmNamespaceT}; use fork::{ForkDetails, ForkSource}; use logging_middleware::LoggingMiddleware; use node::ShowCalls; -use simplelog::{ - ColorChoice, CombinedLogger, ConfigBuilder, LevelFilter, TermLogger, TerminalMode, WriteLogger, -}; +use observability::LogLevel; +use tracing_subscriber::filter::LevelFilter; use zks::ZkMockNamespaceImpl; mod bootloader_debug; @@ -27,6 +27,7 @@ mod hardhat; mod http_fork_source; mod logging_middleware; mod node; +pub mod observability; mod resolver; mod system_contracts; mod testing; @@ -36,16 +37,13 @@ mod zks; use node::InMemoryNode; use zksync_core::api_server::web3::namespaces::NetNamespace; +use std::fs::File; use std::{ env, - fs::File, net::{IpAddr, Ipv4Addr, SocketAddr}, str::FromStr, }; -use tracing::Level; -use tracing_subscriber::{EnvFilter, FmtSubscriber}; - use futures::{ channel::oneshot, future::{self}, @@ -151,28 +149,6 @@ async fn build_json_http< tokio::spawn(recv.map(drop)) } -/// Log filter level for the node. -#[derive(Debug, Clone, ValueEnum)] -enum LogLevel { - Trace, - Debug, - Info, - Warn, - Error, -} - -impl From for LevelFilter { - fn from(value: LogLevel) -> Self { - match value { - LogLevel::Trace => LevelFilter::Trace, - LogLevel::Debug => LevelFilter::Debug, - LogLevel::Info => LevelFilter::Info, - LogLevel::Warn => LevelFilter::Warn, - LogLevel::Error => LevelFilter::Error, - } - } -} - /// Cache type config for the node. #[derive(ValueEnum, Debug, Clone)] enum CacheType { @@ -285,29 +261,16 @@ struct ReplayArgs { #[tokio::main] async fn main() -> anyhow::Result<()> { let opt = Cli::parse(); - let log_level_filter = LevelFilter::from(opt.log); - let log_config = ConfigBuilder::new() - .add_filter_allow_str("era_test_node") - .build(); - CombinedLogger::init(vec![ - TermLogger::new( - log_level_filter, - log_config.clone(), - TerminalMode::Mixed, - ColorChoice::Auto, - ), - WriteLogger::new( - log_level_filter, - log_config, - File::create(opt.log_file_path).unwrap(), - ), - ]) - .expect("failed instantiating logger"); + let log_file = File::create(opt.log_file_path)?; + + // Initialize the tracing subscriber + let observability = + Observability::init(String::from("era_test_node"), log_level_filter, log_file)?; if matches!(opt.dev_system_contracts, DevSystemContracts::Local) { if let Some(path) = env::var_os("ZKSYNC_HOME") { - log::info!("+++++ Reading local contracts from {:?} +++++", path); + tracing::info!("+++++ Reading local contracts from {:?} +++++", path); } } let cache_config = match opt.cache { @@ -319,15 +282,6 @@ async fn main() -> anyhow::Result<()> { }, }; - let filter = EnvFilter::from_default_env(); - let subscriber = FmtSubscriber::builder() - .with_max_level(Level::TRACE) - .with_env_filter(filter) - .finish(); - - // Initialize the subscriber - tracing::subscriber::set_global_default(subscriber).expect("failed to set tracing subscriber"); - let fork_details = match &opt.command { Command::Run => None, Command::Fork(fork) => { @@ -357,27 +311,30 @@ async fn main() -> anyhow::Result<()> { let node = InMemoryNode::new( fork_details, - opt.show_calls, - opt.show_storage_logs, - opt.show_vm_details, - opt.show_gas_details, - opt.resolve_hashes, - &system_contracts_options, + Some(observability), + InMemoryNodeConfig { + show_calls: opt.show_calls, + show_storage_logs: opt.show_storage_logs, + show_vm_details: opt.show_vm_details, + show_gas_details: opt.show_gas_details, + resolve_hashes: opt.resolve_hashes, + system_contracts_options, + }, ); if !transactions_to_replay.is_empty() { let _ = node.apply_txs(transactions_to_replay); } - log::info!("Rich Accounts"); - log::info!("============="); + tracing::info!("Rich Accounts"); + tracing::info!("============="); for (index, wallet) in RICH_WALLETS.iter().enumerate() { let address = wallet.0; let private_key = wallet.1; node.set_rich_account(H160::from_str(address).unwrap()); - log::info!("Account #{}: {} (1_000_000_000_000 ETH)", index, address); - log::info!("Private Key: {}", private_key); - log::info!(""); + tracing::info!("Account #{}: {} (1_000_000_000_000 ETH)", index, address); + tracing::info!("Private Key: {}", private_key); + tracing::info!(""); } let net = NetNamespace::new(L2ChainId::from(TEST_NODE_NETWORK_ID)); @@ -400,9 +357,9 @@ async fn main() -> anyhow::Result<()> { ) .await; - log::info!("========================================"); - log::info!(" Node is ready at 127.0.0.1:{}", opt.port); - log::info!("========================================"); + tracing::info!("========================================"); + tracing::info!(" Node is ready at 127.0.0.1:{}", opt.port); + tracing::info!("========================================"); future::select_all(vec![threads]).await.0.unwrap(); diff --git a/src/node.rs b/src/node.rs index f7abe63c..92763478 100644 --- a/src/node.rs +++ b/src/node.rs @@ -6,6 +6,7 @@ use crate::{ filters::{EthFilters, FilterType, LogFilter}, fork::{ForkDetails, ForkSource, ForkStorage}, formatter, + observability::Observability, system_contracts::{self, Options, SystemContracts}, utils::{ self, adjust_l1_gas_price_for_tx, bytecode_to_factory_dep, create_debug_output, @@ -125,8 +126,9 @@ pub struct TxExecutionInfo { pub result: VmExecutionResultAndLogs, } -#[derive(Debug, clap::Parser, Clone, clap::ValueEnum, PartialEq, Eq)] +#[derive(Debug, Default, clap::Parser, Clone, clap::ValueEnum, PartialEq, Eq)] pub enum ShowCalls { + #[default] None, User, System, @@ -156,8 +158,9 @@ impl Display for ShowCalls { } } -#[derive(Debug, Parser, Clone, clap::ValueEnum, PartialEq, Eq)] +#[derive(Debug, Default, Parser, Clone, clap::ValueEnum, PartialEq, Eq)] pub enum ShowStorageLogs { + #[default] None, Read, Write, @@ -187,8 +190,9 @@ impl Display for ShowStorageLogs { } } -#[derive(Debug, Parser, Clone, clap::ValueEnum, PartialEq, Eq)] +#[derive(Debug, Default, Parser, Clone, clap::ValueEnum, PartialEq, Eq)] pub enum ShowVMDetails { + #[default] None, All, } @@ -214,8 +218,9 @@ impl Display for ShowVMDetails { } } -#[derive(Debug, Parser, Clone, clap::ValueEnum, PartialEq, Eq)] +#[derive(Debug, Default, Parser, Clone, clap::ValueEnum, PartialEq, Eq)] pub enum ShowGasDetails { + #[default] None, All, } @@ -306,6 +311,8 @@ pub struct InMemoryNodeInner { pub rich_accounts: HashSet, /// Keeps track of historical states indexed via block hash. Limited to [MAX_PREVIOUS_STATES]. pub previous_states: IndexMap>, + /// An optional handle to the observability stack + pub observability: Option, } type L2TxResult = ( @@ -480,10 +487,10 @@ impl InMemoryNodeInner { let mut upper_bound = MAX_L2_TX_GAS_LIMIT as u32; let mut attempt_count = 1; - log::trace!("Starting gas estimation loop"); + tracing::trace!("Starting gas estimation loop"); while lower_bound + ESTIMATE_GAS_ACCEPTABLE_OVERESTIMATION < upper_bound { let mid = (lower_bound + upper_bound) / 2; - log::trace!( + tracing::trace!( "Attempt {} (lower_bound: {}, upper_bound: {}, mid: {})", attempt_count, lower_bound, @@ -503,19 +510,19 @@ impl InMemoryNodeInner { ); if estimate_gas_result.result.is_failed() { - log::trace!("Attempt {} FAILED", attempt_count); + tracing::trace!("Attempt {} FAILED", attempt_count); lower_bound = mid + 1; } else { - log::trace!("Attempt {} SUCCEEDED", attempt_count); + tracing::trace!("Attempt {} SUCCEEDED", attempt_count); upper_bound = mid; } attempt_count += 1; } - log::trace!("Gas Estimation Values:"); - log::trace!(" Final upper_bound: {}", upper_bound); - log::trace!(" ESTIMATE_GAS_SCALE_FACTOR: {}", ESTIMATE_GAS_SCALE_FACTOR); - log::trace!(" MAX_L2_TX_GAS_LIMIT: {}", MAX_L2_TX_GAS_LIMIT); + tracing::trace!("Gas Estimation Values:"); + tracing::trace!(" Final upper_bound: {}", upper_bound); + tracing::trace!(" ESTIMATE_GAS_SCALE_FACTOR: {}", ESTIMATE_GAS_SCALE_FACTOR); + tracing::trace!(" MAX_L2_TX_GAS_LIMIT: {}", MAX_L2_TX_GAS_LIMIT); let tx_body_gas_limit = cmp::min( MAX_L2_TX_GAS_LIMIT as u32, (upper_bound as f32 * ESTIMATE_GAS_SCALE_FACTOR) as u32, @@ -542,8 +549,8 @@ impl InMemoryNodeInner { match estimate_gas_result.result { ExecutionResult::Revert { output } => { - log::info!("{}", format!("Unable to estimate gas for the request with our suggested gas limit of {}. The transaction is most likely unexecutable. Breakdown of estimation:", suggested_gas_limit + overhead).red()); - log::info!( + tracing::info!("{}", format!("Unable to estimate gas for the request with our suggested gas limit of {}. The transaction is most likely unexecutable. Breakdown of estimation:", suggested_gas_limit + overhead).red()); + tracing::info!( "{}", format!( "\tEstimated transaction body gas cost: {}", @@ -551,11 +558,11 @@ impl InMemoryNodeInner { ) .red() ); - log::info!( + tracing::info!( "{}", format!("\tGas for pubdata: {}", gas_for_bytecodes_pubdata).red() ); - log::info!("{}", format!("\tOverhead: {}", overhead).red()); + tracing::info!("{}", format!("\tOverhead: {}", overhead).red()); let message = output.to_string(); let pretty_message = format!( "execution reverted{}{}", @@ -563,15 +570,15 @@ impl InMemoryNodeInner { message ); let data = output.encoded_data(); - log::info!("{}", pretty_message.on_red()); + tracing::info!("{}", pretty_message.on_red()); Err(into_jsrpc_error(Web3Error::SubmitTransactionError( pretty_message, data, ))) } ExecutionResult::Halt { reason } => { - log::info!("{}", format!("Unable to estimate gas for the request with our suggested gas limit of {}. The transaction is most likely unexecutable. Breakdown of estimation:", suggested_gas_limit + overhead).red()); - log::info!( + tracing::info!("{}", format!("Unable to estimate gas for the request with our suggested gas limit of {}. The transaction is most likely unexecutable. Breakdown of estimation:", suggested_gas_limit + overhead).red()); + tracing::info!( "{}", format!( "\tEstimated transaction body gas cost: {}", @@ -579,11 +586,11 @@ impl InMemoryNodeInner { ) .red() ); - log::info!( + tracing::info!( "{}", format!("\tGas for pubdata: {}", gas_for_bytecodes_pubdata).red() ); - log::info!("{}", format!("\tOverhead: {}", overhead).red()); + tracing::info!("{}", format!("\tOverhead: {}", overhead).red()); let message = reason.to_string(); let pretty_message = format!( "execution reverted{}{}", @@ -591,7 +598,7 @@ impl InMemoryNodeInner { message ); - log::info!("{}", pretty_message.on_red()); + tracing::info!("{}", pretty_message.on_red()); Err(into_jsrpc_error(Web3Error::SubmitTransactionError( pretty_message, vec![], @@ -603,8 +610,8 @@ impl InMemoryNodeInner { { (value, false) => value, (_, true) => { - log::info!("{}", "Overflow when calculating gas estimation. We've exceeded the block gas limit by summing the following values:".red()); - log::info!( + tracing::info!("{}", "Overflow when calculating gas estimation. We've exceeded the block gas limit by summing the following values:".red()); + tracing::info!( "{}", format!( "\tEstimated transaction body gas cost: {}", @@ -612,11 +619,11 @@ impl InMemoryNodeInner { ) .red() ); - log::info!( + tracing::info!( "{}", format!("\tGas for pubdata: {}", gas_for_bytecodes_pubdata).red() ); - log::info!("{}", format!("\tOverhead: {}", overhead).red()); + tracing::info!("{}", format!("\tOverhead: {}", overhead).red()); return Err(into_jsrpc_error(Web3Error::SubmitTransactionError( "exceeds block gas limit".into(), Default::default(), @@ -624,11 +631,11 @@ impl InMemoryNodeInner { } }; - log::trace!("Gas Estimation Results"); - log::trace!(" tx_body_gas_limit: {}", tx_body_gas_limit); - log::trace!(" gas_for_bytecodes_pubdata: {}", gas_for_bytecodes_pubdata); - log::trace!(" overhead: {}", overhead); - log::trace!(" full_gas_limit: {}", full_gas_limit); + tracing::trace!("Gas Estimation Results"); + tracing::trace!(" tx_body_gas_limit: {}", tx_body_gas_limit); + tracing::trace!(" gas_for_bytecodes_pubdata: {}", gas_for_bytecodes_pubdata); + tracing::trace!(" overhead: {}", overhead); + tracing::trace!(" full_gas_limit: {}", full_gas_limit); let fee = Fee { max_fee_per_gas: base_fee.into(), max_priority_fee_per_gas: 0u32.into(), @@ -713,10 +720,10 @@ impl InMemoryNodeInner { pub fn archive_state(&mut self) -> Result<(), String> { if self.previous_states.len() > MAX_PREVIOUS_STATES as usize { if let Some(entry) = self.previous_states.shift_remove_index(0) { - log::debug!("removing archived state for previous block {:#x}", entry.0); + tracing::debug!("removing archived state for previous block {:#x}", entry.0); } } - log::debug!( + tracing::debug!( "archiving state for {:#x} #{}", self.current_miniblock_hash, self.current_miniblock @@ -811,6 +818,17 @@ pub struct Snapshot { pub(crate) factory_dep_cache: HashMap>>, } +/// Defines the configuration parameters for the [InMemoryNode]. +#[derive(Default, Debug, Clone)] +pub struct InMemoryNodeConfig { + pub show_calls: ShowCalls, + pub show_storage_logs: ShowStorageLogs, + pub show_vm_details: ShowVMDetails, + pub show_gas_details: ShowGasDetails, + pub resolve_hashes: bool, + pub system_contracts_options: system_contracts::Options, +} + /// In-memory node, that can be used for local & unit testing. /// It also supports the option of forking testnet/mainnet. /// All contents are removed when object is destroyed. @@ -831,27 +849,15 @@ fn contract_address_from_tx_result(execution_result: &VmExecutionResultAndLogs) impl Default for InMemoryNode { fn default() -> Self { - InMemoryNode::new( - None, - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, - ) + InMemoryNode::new(None, None, InMemoryNodeConfig::default()) } } impl InMemoryNode { pub fn new( fork: Option>, - show_calls: ShowCalls, - show_storage_logs: ShowStorageLogs, - show_vm_details: ShowVMDetails, - show_gas_details: ShowGasDetails, - resolve_hashes: bool, - system_contracts_options: &system_contracts::Options, + observability: Option, + config: InMemoryNodeConfig, ) -> Self { let inner = if let Some(f) = &fork { let mut block_hashes = HashMap::::new(); @@ -869,17 +875,18 @@ impl InMemoryNode { blocks, block_hashes, filters: Default::default(), - fork_storage: ForkStorage::new(fork, system_contracts_options), - show_calls, - show_storage_logs, - show_vm_details, - show_gas_details, - resolve_hashes, + fork_storage: ForkStorage::new(fork, &config.system_contracts_options), + show_calls: config.show_calls, + show_storage_logs: config.show_storage_logs, + show_vm_details: config.show_vm_details, + show_gas_details: config.show_gas_details, + resolve_hashes: config.resolve_hashes, console_log_handler: ConsoleLogHandler::default(), - system_contracts: SystemContracts::from_options(system_contracts_options), + system_contracts: SystemContracts::from_options(&config.system_contracts_options), impersonated_accounts: Default::default(), rich_accounts: HashSet::new(), previous_states: Default::default(), + observability, } } else { let mut block_hashes = HashMap::::new(); @@ -900,17 +907,18 @@ impl InMemoryNode { blocks, block_hashes, filters: Default::default(), - fork_storage: ForkStorage::new(fork, system_contracts_options), - show_calls, - show_storage_logs, - show_vm_details, - show_gas_details, - resolve_hashes, + fork_storage: ForkStorage::new(fork, &config.system_contracts_options), + show_calls: config.show_calls, + show_storage_logs: config.show_storage_logs, + show_vm_details: config.show_vm_details, + show_gas_details: config.show_gas_details, + resolve_hashes: config.resolve_hashes, console_log_handler: ConsoleLogHandler::default(), - system_contracts: SystemContracts::from_options(system_contracts_options), + system_contracts: SystemContracts::from_options(&config.system_contracts_options), impersonated_accounts: Default::default(), rich_accounts: HashSet::new(), previous_states: Default::default(), + observability, } }; @@ -925,7 +933,7 @@ impl InMemoryNode { /// Applies multiple transactions - but still one per L1 batch. pub fn apply_txs(&self, txs: Vec) -> Result<(), String> { - log::info!("Running {:?} transactions (one per batch)", txs.len()); + tracing::info!("Running {:?} transactions (one per batch)", txs.len()); for tx in txs { self.run_l2_tx(tx, TxExecutionMode::VerifyExecute)?; @@ -941,7 +949,7 @@ impl InMemoryNode { let mut inner = match self.inner.write() { Ok(guard) => guard, Err(e) => { - log::info!("Failed to acquire write lock: {}", e); + tracing::info!("Failed to acquire write lock: {}", e); return; } }; @@ -1003,22 +1011,24 @@ impl InMemoryNode { match &tx_result.result { ExecutionResult::Success { output } => { - log::info!("Call: {}", "SUCCESS".green()); + tracing::info!("Call: {}", "SUCCESS".green()); let output_bytes = zksync_basic_types::Bytes::from(output.clone()); - log::info!("Output: {}", serde_json::to_string(&output_bytes).unwrap()); + tracing::info!("Output: {}", serde_json::to_string(&output_bytes).unwrap()); } ExecutionResult::Revert { output } => { - log::info!("Call: {}: {}", "FAILED".red(), output); + tracing::info!("Call: {}: {}", "FAILED".red(), output); + } + ExecutionResult::Halt { reason } => { + tracing::info!("Call: {} {}", "HALTED".red(), reason) } - ExecutionResult::Halt { reason } => log::info!("Call: {} {}", "HALTED".red(), reason), }; - log::info!("=== Console Logs: "); + tracing::info!("=== Console Logs: "); for call in &call_traces { inner.console_log_handler.handle_call_recursive(call); } - log::info!("=== Call traces:"); + tracing::info!("=== Call traces:"); for call in &call_traces { formatter::print_call(call, 0, &inner.show_calls, inner.resolve_hashes); } @@ -1032,151 +1042,157 @@ impl InMemoryNode { spent_on_pubdata: u32, ) -> eyre::Result<(), String> { if let Some(bootloader_result) = bootloader_debug_result { - let debug = bootloader_result.clone()?; + let bootloader_debug = bootloader_result.clone()?; - log::info!("┌─────────────────────────┐"); - log::info!("│ GAS DETAILS │"); - log::info!("└─────────────────────────┘"); + tracing::info!("┌─────────────────────────┐"); + tracing::info!("│ GAS DETAILS │"); + tracing::info!("└─────────────────────────┘"); // Total amount of gas (should match tx.gas_limit). - let total_gas_limit = debug + let total_gas_limit = bootloader_debug .total_gas_limit_from_user - .saturating_sub(debug.reserved_gas); + .saturating_sub(bootloader_debug.reserved_gas); - let intrinsic_gas = total_gas_limit - debug.gas_limit_after_intrinsic; - let gas_for_validation = debug.gas_limit_after_intrinsic - debug.gas_after_validation; + let intrinsic_gas = total_gas_limit - bootloader_debug.gas_limit_after_intrinsic; + let gas_for_validation = + bootloader_debug.gas_limit_after_intrinsic - bootloader_debug.gas_after_validation; - let gas_spent_on_compute = - debug.gas_spent_on_execution - debug.gas_spent_on_bytecode_preparation; + let gas_spent_on_compute = bootloader_debug.gas_spent_on_execution + - bootloader_debug.gas_spent_on_bytecode_preparation; let gas_used = intrinsic_gas + gas_for_validation - + debug.gas_spent_on_bytecode_preparation + + bootloader_debug.gas_spent_on_bytecode_preparation + gas_spent_on_compute; - log::info!( + tracing::info!( "Gas - Limit: {} | Used: {} | Refunded: {}", to_human_size(total_gas_limit), to_human_size(gas_used), - to_human_size(debug.refund_by_operator) + to_human_size(bootloader_debug.refund_by_operator) ); - if debug.total_gas_limit_from_user != total_gas_limit { - log::info!( + if bootloader_debug.total_gas_limit_from_user != total_gas_limit { + tracing::info!( "{}", format!( " WARNING: user actually provided more gas {}, but system had a lower max limit.", - to_human_size(debug.total_gas_limit_from_user) + to_human_size(bootloader_debug.total_gas_limit_from_user) ) .yellow() ); } - if debug.refund_computed != debug.refund_by_operator { - log::info!( + if bootloader_debug.refund_computed != bootloader_debug.refund_by_operator { + tracing::info!( "{}", format!( " WARNING: Refund by VM: {}, but operator refunded more: {}", - to_human_size(debug.refund_computed), - to_human_size(debug.refund_by_operator) + to_human_size(bootloader_debug.refund_computed), + to_human_size(bootloader_debug.refund_by_operator) ) .yellow() ); } - if debug.refund_computed + gas_used != total_gas_limit { - log::info!( + if bootloader_debug.refund_computed + gas_used != total_gas_limit { + tracing::info!( "{}", format!( " WARNING: Gas totals don't match. {} != {} , delta: {}", - to_human_size(debug.refund_computed + gas_used), + to_human_size(bootloader_debug.refund_computed + gas_used), to_human_size(total_gas_limit), - to_human_size(total_gas_limit.abs_diff(debug.refund_computed + gas_used)) + to_human_size( + total_gas_limit.abs_diff(bootloader_debug.refund_computed + gas_used) + ) ) .yellow() ); } - let bytes_published = spent_on_pubdata / debug.gas_per_pubdata.as_u32(); + let bytes_published = spent_on_pubdata / bootloader_debug.gas_per_pubdata.as_u32(); - log::info!( + tracing::info!( "During execution published {} bytes to L1, @{} each - in total {} gas", to_human_size(bytes_published.into()), - to_human_size(debug.gas_per_pubdata), + to_human_size(bootloader_debug.gas_per_pubdata), to_human_size(spent_on_pubdata.into()) ); - log::info!("Out of {} gas used, we spent:", to_human_size(gas_used)); - log::info!( + tracing::info!("Out of {} gas used, we spent:", to_human_size(gas_used)); + tracing::info!( " {:>15} gas ({:>2}%) for transaction setup", to_human_size(intrinsic_gas), to_human_size(intrinsic_gas * 100 / gas_used) ); - log::info!( + tracing::info!( " {:>15} gas ({:>2}%) for bytecode preparation (decompression etc)", - to_human_size(debug.gas_spent_on_bytecode_preparation), - to_human_size(debug.gas_spent_on_bytecode_preparation * 100 / gas_used) + to_human_size(bootloader_debug.gas_spent_on_bytecode_preparation), + to_human_size(bootloader_debug.gas_spent_on_bytecode_preparation * 100 / gas_used) ); - log::info!( + tracing::info!( " {:>15} gas ({:>2}%) for account validation", to_human_size(gas_for_validation), to_human_size(gas_for_validation * 100 / gas_used) ); - log::info!( + tracing::info!( " {:>15} gas ({:>2}%) for computations (opcodes)", to_human_size(gas_spent_on_compute), to_human_size(gas_spent_on_compute * 100 / gas_used) ); - log::info!(""); - log::info!(""); - log::info!( + tracing::info!(""); + tracing::info!(""); + tracing::info!( "{}", "=== Transaction setup cost breakdown ===".to_owned().bold(), ); - log::info!("Total cost: {}", to_human_size(intrinsic_gas).bold()); - log::info!( + tracing::info!("Total cost: {}", to_human_size(intrinsic_gas).bold()); + tracing::info!( " {:>15} gas ({:>2}%) fixed cost", - to_human_size(debug.intrinsic_overhead), - to_human_size(debug.intrinsic_overhead * 100 / intrinsic_gas) + to_human_size(bootloader_debug.intrinsic_overhead), + to_human_size(bootloader_debug.intrinsic_overhead * 100 / intrinsic_gas) ); - log::info!( + tracing::info!( " {:>15} gas ({:>2}%) operator cost", - to_human_size(debug.operator_overhead), - to_human_size(debug.operator_overhead * 100 / intrinsic_gas) + to_human_size(bootloader_debug.operator_overhead), + to_human_size(bootloader_debug.operator_overhead * 100 / intrinsic_gas) ); - log::info!(""); - log::info!( + tracing::info!(""); + tracing::info!( " FYI: operator could have charged up to: {}, so you got {}% discount", - to_human_size(debug.required_overhead), + to_human_size(bootloader_debug.required_overhead), to_human_size( - (debug.required_overhead - debug.operator_overhead) * 100 - / debug.required_overhead + (bootloader_debug.required_overhead - bootloader_debug.operator_overhead) * 100 + / bootloader_debug.required_overhead ) ); let publish_block_l1_bytes = BLOCK_OVERHEAD_PUBDATA; - log::info!( + tracing::info!( "Publishing full block costs the operator up to: {}, where {} is due to {} bytes published to L1", - to_human_size(debug.total_overhead_for_block), - to_human_size(debug.gas_per_pubdata * publish_block_l1_bytes), + to_human_size(bootloader_debug.total_overhead_for_block), + to_human_size(bootloader_debug.gas_per_pubdata * publish_block_l1_bytes), to_human_size(publish_block_l1_bytes.into()) ); - log::info!("Your transaction has contributed to filling up the block in the following way (we take the max contribution as the cost):"); - log::info!( + tracing::info!("Your transaction has contributed to filling up the block in the following way (we take the max contribution as the cost):"); + tracing::info!( " Circuits overhead:{:>15} ({}% of the full block: {})", - to_human_size(debug.overhead_for_circuits), - to_human_size(debug.overhead_for_circuits * 100 / debug.total_overhead_for_block), - to_human_size(debug.total_overhead_for_block) + to_human_size(bootloader_debug.overhead_for_circuits), + to_human_size( + bootloader_debug.overhead_for_circuits * 100 + / bootloader_debug.total_overhead_for_block + ), + to_human_size(bootloader_debug.total_overhead_for_block) ); - log::info!( + tracing::info!( " Length overhead: {:>15}", - to_human_size(debug.overhead_for_length) + to_human_size(bootloader_debug.overhead_for_length) ); - log::info!( + tracing::info!( " Slot overhead: {:>15}", - to_human_size(debug.overhead_for_slot) + to_human_size(bootloader_debug.overhead_for_slot) ); Ok(()) } else { @@ -1248,19 +1264,19 @@ impl InMemoryNode { let spent_on_pubdata = tx_result.statistics.gas_used - tx_result.statistics.computational_gas_used; - log::info!("┌─────────────────────────┐"); - log::info!("│ TRANSACTION SUMMARY │"); - log::info!("└─────────────────────────┘"); + tracing::info!("┌─────────────────────────┐"); + tracing::info!("│ TRANSACTION SUMMARY │"); + tracing::info!("└─────────────────────────┘"); match &tx_result.result { - ExecutionResult::Success { .. } => log::info!("Transaction: {}", "SUCCESS".green()), - ExecutionResult::Revert { .. } => log::info!("Transaction: {}", "FAILED".red()), - ExecutionResult::Halt { .. } => log::info!("Transaction: {}", "HALTED".red()), + ExecutionResult::Success { .. } => tracing::info!("Transaction: {}", "SUCCESS".green()), + ExecutionResult::Revert { .. } => tracing::info!("Transaction: {}", "FAILED".red()), + ExecutionResult::Halt { .. } => tracing::info!("Transaction: {}", "HALTED".red()), } - log::info!("Initiator: {:?}", tx.initiator_account()); - log::info!("Payer: {:?}", tx.payer()); - log::info!( + tracing::info!("Initiator: {:?}", tx.initiator_account()); + tracing::info!("Payer: {:?}", tx.payer()); + tracing::info!( "Gas - Limit: {} | Used: {} | Refunded: {}", to_human_size(tx.gas_limit()), to_human_size(tx.gas_limit() - tx_result.refunds.gas_refunded), @@ -1268,7 +1284,7 @@ impl InMemoryNode { ); match inner.show_gas_details { - ShowGasDetails::None => log::info!( + ShowGasDetails::None => tracing::info!( "Use --show-gas-details flag or call config_setShowGasDetails to display more info" ), ShowGasDetails::All => { @@ -1276,7 +1292,7 @@ impl InMemoryNode { .display_detailed_gas_info(bootloader_debug_result.get(), spent_on_pubdata) .is_err() { - log::info!( + tracing::info!( "{}", "!!! FAILED TO GET DETAILED GAS INFO !!!".to_owned().red() ); @@ -1285,10 +1301,10 @@ impl InMemoryNode { } if inner.show_storage_logs != ShowStorageLogs::None { - log::info!(""); - log::info!("┌──────────────────┐"); - log::info!("│ STORAGE LOGS │"); - log::info!("└──────────────────┘"); + tracing::info!(""); + tracing::info!("┌──────────────────┐"); + tracing::info!("│ STORAGE LOGS │"); + tracing::info!("└──────────────────┘"); } for log_query in &tx_result.logs.storage_logs { @@ -1317,19 +1333,19 @@ impl InMemoryNode { formatter::print_vm_details(&tx_result); } - log::info!(""); - log::info!("==== Console logs: "); + tracing::info!(""); + tracing::info!("==== Console logs: "); for call in call_traces { inner.console_log_handler.handle_call_recursive(call); } - log::info!(""); + tracing::info!(""); let call_traces_count = if !call_traces.is_empty() { // All calls/sub-calls are stored within the first call trace call_traces[0].calls.len() } else { 0 }; - log::info!( + tracing::info!( "==== {} Use --show-calls flag or call config_setShowCalls to display more info.", format!("{:?} call traces. ", call_traces_count).bold() ); @@ -1339,8 +1355,8 @@ impl InMemoryNode { formatter::print_call(call, 0, &inner.show_calls, inner.resolve_hashes); } } - log::info!(""); - log::info!( + tracing::info!(""); + tracing::info!( "==== {}", format!("{} events", tx_result.logs.events.len()).bold() ); @@ -1373,8 +1389,8 @@ impl InMemoryNode { ..Default::default() }; - log::info!(""); - log::info!(""); + tracing::info!(""); + tracing::info!(""); let bytecodes = vm .get_last_tx_compressed_bytecodes() @@ -1398,8 +1414,8 @@ impl InMemoryNode { /// Runs L2 transaction and commits it to a new block. fn run_l2_tx(&self, l2_tx: L2Tx, execution_mode: TxExecutionMode) -> Result<(), String> { let tx_hash = l2_tx.hash(); - log::info!(""); - log::info!("Executing {}", format!("{:?}", tx_hash).bold()); + tracing::info!(""); + tracing::info!("Executing {}", format!("{:?}", tx_hash).bold()); { let mut inner = self @@ -1528,7 +1544,7 @@ impl InMemoryNode { for block in vec![block, empty_block_at_end_of_batch] { // archive current state before we produce new batch/blocks if let Err(err) = inner.archive_state() { - log::error!( + tracing::error!( "failed archiving state for block {}: {}", inner.current_miniblock, err @@ -1655,7 +1671,7 @@ impl EthNamespaceT for message ); - log::info!("{}", pretty_message.on_red()); + tracing::info!("{}", pretty_message.on_red()); Err(into_jsrpc_error(Web3Error::SubmitTransactionError( pretty_message, output.encoded_data(), @@ -1670,7 +1686,7 @@ impl EthNamespaceT for message ); - log::info!("{}", pretty_message.on_red()); + tracing::info!("{}", pretty_message.on_red()); Err(into_jsrpc_error(Web3Error::SubmitTransactionError( pretty_message, vec![], @@ -2576,7 +2592,10 @@ impl EthNamespaceT for .get(&o.block_hash) .map(|block| block.number) .ok_or_else(|| { - log::error!("unable to map block number to hash #{:#x}", o.block_hash); + tracing::error!( + "unable to map block number to hash #{:#x}", + o.block_hash + ); into_jsrpc_error(Web3Error::InternalError) }), }) @@ -2608,7 +2627,7 @@ impl EthNamespaceT for .as_ref() .and_then(|fork| fork.fork_source.get_storage_at(address, idx, block).ok()) .ok_or_else(|| { - log::error!( + tracing::error!( "unable to get storage at address {:?}, index {:?} for block {:?}", address, idx, @@ -3034,12 +3053,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let inner = node.inner.read().unwrap(); @@ -3081,12 +3096,8 @@ mod tests { ); let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_block = node @@ -3153,12 +3164,8 @@ mod tests { ); let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_block = node @@ -3205,12 +3212,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_block = node @@ -3245,12 +3248,8 @@ mod tests { ); let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_block = node @@ -3276,12 +3275,8 @@ mod tests { }); let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_block = node @@ -3338,12 +3333,8 @@ mod tests { ); let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_transaction_count = node @@ -3399,12 +3390,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_transaction_count = node @@ -3445,12 +3432,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_transaction_count = node @@ -3482,12 +3465,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_transaction_count = node @@ -3760,12 +3739,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_value = node @@ -3859,12 +3834,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); node.inner .write() @@ -4463,12 +4434,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); // store the block info with just the tx hash invariant @@ -4521,12 +4488,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_tx = node @@ -4620,12 +4583,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); // store the block info with just the tx hash invariant @@ -4685,12 +4644,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let actual_tx = node diff --git a/src/observability.rs b/src/observability.rs new file mode 100644 index 00000000..1c2bbb1e --- /dev/null +++ b/src/observability.rs @@ -0,0 +1,126 @@ +use core::fmt; +use std::{fs::File, sync::Mutex}; + +use clap::ValueEnum; +use serde::{Deserialize, Serialize}; +use tracing_subscriber::{ + filter::LevelFilter, layer::SubscriberExt, reload, util::SubscriberInitExt, EnvFilter, Layer, + Registry, +}; + +/// Log filter level for the node. +#[derive(Debug, Clone, ValueEnum, Serialize, Deserialize)] +#[serde(rename_all = "lowercase")] +pub enum LogLevel { + Trace, + Debug, + Info, + Warn, + Error, +} + +impl fmt::Display for LogLevel { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + match *self { + LogLevel::Trace => f.pad("TRACE"), + LogLevel::Debug => f.pad("DEBUG"), + LogLevel::Info => f.pad("INFO"), + LogLevel::Warn => f.pad("WARN"), + LogLevel::Error => f.pad("ERROR"), + } + } +} + +impl From for LevelFilter { + fn from(value: LogLevel) -> Self { + match value { + LogLevel::Trace => LevelFilter::TRACE, + LogLevel::Debug => LevelFilter::DEBUG, + LogLevel::Info => LevelFilter::INFO, + LogLevel::Warn => LevelFilter::WARN, + LogLevel::Error => LevelFilter::ERROR, + } + } +} + +/// A sharable reference to the observability stack. +#[derive(Debug, Default, Clone)] +pub struct Observability { + binary_name: String, + reload_handle: Option>, +} + +impl Observability { + /// Initialize the tracing subscriber. + pub fn init( + binary_name: String, + log_level_filter: LevelFilter, + log_file: File, + ) -> Result { + let filter = Self::parse_filter(&format!( + "{}={}", + binary_name, + format!("{log_level_filter}").to_lowercase() + ))?; + let (filter, reload_handle) = reload::Layer::new(filter); + tracing_subscriber::registry() + .with( + filter.and_then(tracing_subscriber::fmt::layer()).and_then( + tracing_subscriber::fmt::layer() + .with_writer(Mutex::new(log_file)) + .with_ansi(false), + ), + ) + .init(); + + Ok(Self { + binary_name, + reload_handle: Some(reload_handle), + }) + } + + /// Set the log level for the binary. + pub fn set_log_level(&self, level: LogLevel) -> Result<(), anyhow::Error> { + let level = LevelFilter::from(level); + let new_filter = Self::parse_filter(&format!( + "{}={}", + self.binary_name, + format!("{level}").to_lowercase() + ))?; + + if let Some(handle) = &self.reload_handle { + handle.modify(|filter| *filter = new_filter)?; + } + + Ok(()) + } + + /// Sets advanced logging directive. + /// Example: + /// * "my_crate=debug" + /// * "my_crate::module=trace" + /// * "my_crate=debug,other_crate=warn" + pub fn set_logging(&self, directive: &str) -> Result<(), anyhow::Error> { + let new_filter = Self::parse_filter(directive)?; + + if let Some(handle) = &self.reload_handle { + handle.modify(|filter| *filter = new_filter)?; + } + + Ok(()) + } + + /// Parses a directive and builds an [EnvFilter] from it. + /// Example: + /// * "my_crate=debug" + /// * "my_crate::module=trace" + /// * "my_crate=debug,other_crate=warn" + fn parse_filter(directive: &str) -> Result { + let mut filter = EnvFilter::from_default_env(); + for directive in directive.split(',') { + filter = filter.add_directive(directive.parse()?); + } + + Ok(filter) + } +} diff --git a/src/system_contracts.rs b/src/system_contracts.rs index bf2a6409..aa53c292 100644 --- a/src/system_contracts.rs +++ b/src/system_contracts.rs @@ -9,8 +9,10 @@ use zksync_utils::{bytecode::hash_bytecode, bytes_to_be_words}; use crate::deps::system_contracts::{bytecode_from_slice, COMPILED_IN_SYSTEM_CONTRACTS}; +#[derive(Default, Debug, Clone)] pub enum Options { // Use the compiled-in contracts + #[default] BuiltIn, // Load the contracts bytecode at runtime from ZKSYNC_HOME Local, diff --git a/src/utils.rs b/src/utils.rs index ea53c4ae..75f5ae8f 100644 --- a/src/utils.rs +++ b/src/utils.rs @@ -190,7 +190,7 @@ pub fn to_real_block_number(block_number: BlockNumber, latest_block_number: U64) pub fn not_implemented( method_name: &str, ) -> jsonrpc_core::BoxFuture> { - log::warn!("Method {} is not implemented", method_name); + tracing::warn!("Method {} is not implemented", method_name); Err(jsonrpc_core::Error { data: None, code: jsonrpc_core::ErrorCode::MethodNotFound, diff --git a/src/zks.rs b/src/zks.rs index 9fc2bd4f..67741a57 100644 --- a/src/zks.rs +++ b/src/zks.rs @@ -113,7 +113,7 @@ impl ZksNamespaceT .as_ref() { Some(fork) => fork.fork_source.get_bridge_contracts().map_err(|err| { - log::error!("failed fetching bridge contracts from the fork: {:?}", err); + tracing::error!("failed fetching bridge contracts from the fork: {:?}", err); into_jsrpc_error(Web3Error::InternalError) })?, None => BridgeAddresses { @@ -168,7 +168,7 @@ impl ZksNamespaceT Ok(1.into()).into_boxed_future() } address => { - log::error!( + tracing::error!( "{}", format!("Token price requested for unknown address {:?}", address).red() ); @@ -435,10 +435,9 @@ mod tests { use crate::cache::CacheConfig; use crate::fork::ForkDetails; - use crate::node::{ShowCalls, ShowGasDetails, ShowStorageLogs, ShowVMDetails}; + use crate::testing; use crate::testing::{ForkBlockConfig, MockServer}; use crate::{http_fork_source::HttpForkSource, node::InMemoryNode}; - use crate::{system_contracts, testing}; use super::*; use zksync_basic_types::{Address, H160, H256}; @@ -500,15 +499,7 @@ mod tests { #[tokio::test] async fn test_get_token_price_given_capitalized_link_address_should_return_price() { // Arrange - let node = InMemoryNode::::new( - None, - ShowCalls::None, - crate::node::ShowStorageLogs::None, - crate::node::ShowVMDetails::None, - crate::node::ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, - ); + let node = InMemoryNode::::default(); let namespace = ZkMockNamespaceImpl::new(node.get_inner()); let mock_address = Address::from_str("0x40609141Db628BeEE3BfAB8034Fc2D8278D0Cc78") @@ -607,12 +598,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let namespace = ZkMockNamespaceImpl::new(node.get_inner()); @@ -699,12 +686,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let namespace = ZkMockNamespaceImpl::new(node.get_inner()); @@ -775,12 +758,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let namespace = ZkMockNamespaceImpl::new(node.get_inner()); @@ -846,12 +825,8 @@ mod tests { let node = InMemoryNode::::new( Some(ForkDetails::from_network(&mock_server.url(), None, CacheConfig::None).await), - crate::node::ShowCalls::None, - ShowStorageLogs::None, - ShowVMDetails::None, - ShowGasDetails::None, - false, - &system_contracts::Options::BuiltIn, + None, + Default::default(), ); let namespace = ZkMockNamespaceImpl::new(node.get_inner()); diff --git a/test_endpoints.http b/test_endpoints.http index 90ef7e79..e1e206ed 100644 --- a/test_endpoints.http +++ b/test_endpoints.http @@ -734,4 +734,26 @@ content-type: application/json "id": "1", "method": "eth_accounts", "params": [] -} \ No newline at end of file +} + +### +POST http://localhost:8011 +content-type: application/json + +{ + "jsonrpc": "2.0", + "id": "1", + "method": "config_setLogLevel", + "params": ["trace"] +} + +### +POST http://localhost:8011 +content-type: application/json + +{ + "jsonrpc": "2.0", + "id": "1", + "method": "config_setLogging", + "params": ["era_test_node=info,hyper=debug"] +}