Skip to content

Commit

Permalink
feat: add logs for incoming API requests (#118)
Browse files Browse the repository at this point in the history
* feat: add logs for incoming API requests

* chore: update unimplemented method log to warning

* chore: add trace LogLevel. Update incoming request logs with full params to Trace. Fix unit test.

* chore: add Trace log for API responses
  • Loading branch information
MexicanAce committed Sep 18, 2023
1 parent 599758f commit 19b7cca
Show file tree
Hide file tree
Showing 7 changed files with 111 additions and 36 deletions.
2 changes: 1 addition & 1 deletion Cargo.lock

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

2 changes: 1 addition & 1 deletion Cargo.toml
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
[package]
name = "era_test_node"
version = "0.1.0"
version = "0.1.0-alpha.3"
edition = "2018"
authors = ["The Matter Labs Team <hello@matterlabs.dev>"]
homepage = "https://zksync.io/"
Expand Down
6 changes: 3 additions & 3 deletions src/hardhat.rs
Original file line number Diff line number Diff line change
Expand Up @@ -239,7 +239,7 @@ mod tests {
.hardhat_mine(None, None)
.await
.expect("hardhat_mine");
assert_eq!(result, true);
assert!(result);

let current_block = node
.get_block_by_number(zksync_types::api::BlockNumber::Latest, false)
Expand All @@ -253,7 +253,7 @@ mod tests {
.hardhat_mine(None, None)
.await
.expect("hardhat_mine");
assert_eq!(result, true);
assert!(result);

let current_block = node
.get_block_by_number(zksync_types::api::BlockNumber::Latest, false)
Expand Down Expand Up @@ -284,7 +284,7 @@ mod tests {
.hardhat_mine(Some(U64::from(num_blocks)), Some(U64::from(interval)))
.await
.expect("hardhat_mine");
assert_eq!(result, true);
assert!(result);

for i in 0..num_blocks {
let current_block = node
Expand Down
93 changes: 93 additions & 0 deletions src/logging_middleware.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,93 @@
use colored::Colorize;
use futures::Future;
use futures::{future::Either, FutureExt};
use itertools::Itertools;
use jsonrpc_core::{
middleware, Call, FutureResponse, Metadata, Middleware, Params, Request, Response,
};
use log::LevelFilter;

#[derive(Clone, Debug, Default)]
pub struct Meta();
impl Metadata for Meta {}

pub struct LoggingMiddleware {
log_level_filter: LevelFilter,
}

impl LoggingMiddleware {
pub fn new(log_level_filter: LevelFilter) -> Self {
Self { log_level_filter }
}
}

/// Logging Middleware for all in-bound requests
/// Logs out incoming requests and their parameters
/// Useful for debugging applications that are pointed at this service
impl Middleware<Meta> for LoggingMiddleware {
type Future = FutureResponse;
type CallFuture = middleware::NoopCallFuture;

fn on_request<F, X>(&self, request: Request, meta: Meta, next: F) -> Either<Self::Future, X>
where
F: FnOnce(Request, Meta) -> X + Send,
X: Future<Output = Option<Response>> + Send + 'static,
{
if let Request::Single(Call::MethodCall(method_call)) = &request {
match self.log_level_filter {
LevelFilter::Trace => {
let full_params = match &method_call.params {
Params::Array(values) => {
if values.is_empty() {
String::default()
} else {
format!("with [{}]", values.iter().join(", "))
}
}
_ => String::default(),
};

log::trace!("{} was called {}", method_call.method.cyan(), full_params);
}
_ => {
// Generate truncated params for requests with massive payloads
let truncated_params = match &method_call.params {
Params::Array(values) => {
if values.is_empty() {
String::default()
} else {
format!(
"with [{}]",
values
.iter()
.map(|s| {
let s_str = s.to_string();
if s_str.len() > 70 {
format!("{:.67}...", s_str)
} else {
s_str
}
})
.collect::<Vec<String>>()
.join(", ")
)
}
}
_ => String::default(),
};

log::info!(
"{} was called {}",
method_call.method.cyan(),
truncated_params
);
}
}
};

Either::Left(Box::pin(next(request, meta).map(move |res| {
log::trace!("API response => {:?}", res);
res
})))
}
}
11 changes: 9 additions & 2 deletions src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ use clap::{Parser, Subcommand, ValueEnum};
use configuration_api::ConfigurationApiNamespaceT;
use evm::{EvmNamespaceImpl, EvmNamespaceT};
use fork::{ForkDetails, ForkSource};
use logging_middleware::LoggingMiddleware;
use node::ShowCalls;
use simplelog::{
ColorChoice, CombinedLogger, ConfigBuilder, LevelFilter, TermLogger, TerminalMode, WriteLogger,
Expand All @@ -21,6 +22,7 @@ mod fork;
mod formatter;
mod hardhat;
mod http_fork_source;
mod logging_middleware;
mod node;
mod resolver;
mod system_contracts;
Expand All @@ -46,7 +48,7 @@ use futures::{
future::{self},
FutureExt,
};
use jsonrpc_core::IoHandler;
use jsonrpc_core::MetaIoHandler;
use zksync_basic_types::{L2ChainId, H160, H256};

use crate::{configuration_api::ConfigurationApiNamespace, node::TEST_NODE_NETWORK_ID};
Expand Down Expand Up @@ -98,10 +100,12 @@ pub const RICH_WALLETS: [(&str, &str); 10] = [
),
];

#[allow(clippy::too_many_arguments)]
async fn build_json_http<
S: std::marker::Sync + std::marker::Send + 'static + ForkSource + std::fmt::Debug,
>(
addr: SocketAddr,
log_level_filter: LevelFilter,
node: InMemoryNode<S>,
net: NetNamespace,
config_api: ConfigurationApiNamespace<S>,
Expand All @@ -112,7 +116,7 @@ async fn build_json_http<
let (sender, recv) = oneshot::channel::<()>();

let io_handler = {
let mut io = IoHandler::new();
let mut io = MetaIoHandler::with_middleware(LoggingMiddleware::new(log_level_filter));
io.extend_with(node.to_delegate());
io.extend_with(net.to_delegate());
io.extend_with(config_api.to_delegate());
Expand Down Expand Up @@ -145,6 +149,7 @@ async fn build_json_http<
/// Log filter level for the node.
#[derive(Debug, Clone, ValueEnum)]
enum LogLevel {
Trace,
Debug,
Info,
Warn,
Expand All @@ -154,6 +159,7 @@ enum LogLevel {
impl From<LogLevel> 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,
Expand Down Expand Up @@ -368,6 +374,7 @@ async fn main() -> anyhow::Result<()> {

let threads = build_json_http(
SocketAddr::new(IpAddr::V4(Ipv4Addr::new(0, 0, 0, 0)), opt.port),
log_level_filter,
node,
net,
config_api,
Expand Down
28 changes: 2 additions & 26 deletions src/node.rs
Original file line number Diff line number Diff line change
Expand Up @@ -562,7 +562,7 @@ impl<S: std::fmt::Debug + ForkSource> InMemoryNodeInner<S> {
fn not_implemented<T: Send + 'static>(
method_name: &str,
) -> jsonrpc_core::BoxFuture<Result<T, jsonrpc_core::Error>> {
log::info!("Method {} is not implemented", method_name);
log::warn!("Method {} is not implemented", method_name);
Err(jsonrpc_core::Error {
data: None,
code: jsonrpc_core::ErrorCode::MethodNotFound,
Expand Down Expand Up @@ -2120,31 +2120,7 @@ mod tests {
async fn test_get_fee_history_with_multiple_blocks() {
// Arrange
let node = InMemoryNode::<HttpForkSource>::default();

let private_key = H256::random();
let from_account = PackedEthSignature::address_from_private_key(&private_key)
.expect("failed generating address");
node.set_rich_account(from_account);
let mut tx = L2Tx::new_signed(
Address::random(),
vec![],
Nonce(0),
Fee {
gas_limit: U256::from(1_000_000),
max_fee_per_gas: U256::from(250_000_000),
max_priority_fee_per_gas: U256::from(250_000_000),
gas_per_pubdata_limit: U256::from(20000),
},
U256::from(1),
L2ChainId(260),
&private_key,
None,
Default::default(),
)
.unwrap();
tx.set_input(vec![], H256::repeat_byte(0x01));

node.apply_txs(vec![tx]).expect("failed applying tx");
testing::apply_tx(&node, H256::repeat_byte(0x01));

// Act
let fee_history = node
Expand Down
5 changes: 2 additions & 3 deletions src/testing.rs
Original file line number Diff line number Diff line change
Expand Up @@ -124,7 +124,6 @@ impl MockServer {
"sealFields": [],
"uncles": [],
"transactions": (0..block_config.transaction_count)
.into_iter()
.map(|index| {
TransactionResponseBuilder::new()
.set_hash(H256::repeat_byte(index))
Expand Down Expand Up @@ -381,7 +380,7 @@ pub fn apply_tx<T: ForkSource + std::fmt::Debug>(node: &InMemoryNode<T>, tx_hash
)
.unwrap();
tx.set_input(vec![], tx_hash);
node.apply_txs(vec![tx.into()]).expect("failed applying tx");
node.apply_txs(vec![tx]).expect("failed applying tx");

produced_block_hash
}
Expand Down Expand Up @@ -463,7 +462,7 @@ mod test {
.as_object()
.and_then(|o| o.get("result").unwrap().as_array())
.map(|o| {
o.into_iter()
o.iter()
.map(|o| o.get("common_data").unwrap().as_object().unwrap())
.map(|o| o.get("L1").unwrap().as_object().unwrap())
.map(|entry| entry.get("serialId").unwrap().as_u64().unwrap())
Expand Down

0 comments on commit 19b7cca

Please sign in to comment.