Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 5 commits into from
Oct 19, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
25 changes: 0 additions & 25 deletions Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

3 changes: 0 additions & 3 deletions Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -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" }
Expand Down Expand Up @@ -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 }
Expand Down
2 changes: 2 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
49 changes: 49 additions & 0 deletions SUPPORTED_APIS.md
Original file line number Diff line number Diff line change
Expand Up @@ -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 |
Expand Down Expand Up @@ -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`
Expand Down
15 changes: 8 additions & 7 deletions src/cache.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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 [
Expand All @@ -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
Expand Down Expand Up @@ -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),
}
}
}
Expand Down
62 changes: 62 additions & 0 deletions src/configuration_api.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand All @@ -13,6 +15,7 @@ use crate::{
node::ShowCalls,
node::ShowVMDetails,
node::{ShowGasDetails, ShowStorageLogs},
observability::LogLevel,
};

pub struct ConfigurationApiNamespace<S> {
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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)
}
}
2 changes: 1 addition & 1 deletion src/console_log.rs
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,7 @@ impl ConsoleLogHandler {
tokens.iter().map(|t| format!("{}", t)).join(" ")
})
});
log::info!("{}", message.cyan());
tracing::info!("{}", message.cyan());
}
}

Expand Down
20 changes: 10 additions & 10 deletions src/evm.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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)),
Expand All @@ -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(())
Expand All @@ -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)
Expand All @@ -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));
}

Expand All @@ -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
Expand Down
Loading