feat: add logs for incoming API requests

Cargo.toml

@@ -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 <[email protected]>"]
 homepage = "https://zksync.io/"

src/hardhat.rs

@@ -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)
@@ -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)
@@ -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

src/logging_middleware.rs

@@ -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
+        })))
+    }
+}

src/main.rs

@@ -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,
@@ -21,6 +22,7 @@ mod fork;
 mod formatter;
 mod hardhat;
 mod http_fork_source;
+mod logging_middleware;
 mod node;
 mod resolver;
 mod system_contracts;
@@ -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};
@@ -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>,
@@ -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());
@@ -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,
@@ -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,
@@ -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,

src/node.rs

@@ -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,
@@ -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

src/testing.rs

@@ -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))
@@ -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
 }
@@ -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())