chore(l1): improve logging on the import subcommand. (#4201)

**Motivation**
Logging in general, and specifically in the `import` subcommand is quite
messy.

**Description**
- Improves the logging phrasing
- Instead of logging for each block, logs a summary every 10 seconds
- Logs the total time that it took.
- Some misc log additions and downgrades

This is how it looks:
```
2025-08-28T17:27:12.121079Z  INFO ethrex_storage::store: Opening storage engine engine=Libmdbx path=/Users/mpaulucci/Library/Application-Support/ethrex
2025-08-28T17:27:12.158692Z  INFO ethrex_storage::store: Storing genesis block hash=0xbbe3…971b
2025-08-28T17:27:12.159567Z  INFO ethrex::initializers: Initiating blockchain evm=levm
2025-08-28T17:27:12.159726Z  INFO ethrex::cli: Importing blocks from file path=./hoodi-1k.rlp
2025-08-28T17:27:22.415021Z  INFO ethrex::cli: Import progress processed=151 total=1000 percent=15.1
2025-08-28T17:27:32.602179Z  INFO ethrex::cli: Import progress processed=180 total=1000 percent=18.0
```

Author: mpaulucci

cmd/ethrex/bench/build_block_benchmark.rs

@@ -256,6 +256,7 @@ pub fn build_block_benchmark(c: &mut Criterion<GasMeasurement>) {
                         EvmEngine::LEVM,
                         store_with_genesis.clone(),
                         BlockchainType::L1, // TODO: Should we support L2?
+                        false,
                     );
                     fill_mempool(&block_chain, accounts).await;
 

cmd/ethrex/cli.rs

@@ -401,14 +401,15 @@ pub async fn import_blocks(
     evm: EvmEngine,
     blockchain_type: BlockchainType,
 ) -> Result<(), ChainError> {
+    let start_time = Instant::now();
     let data_dir = init_datadir(data_dir);
     let store = init_store(&data_dir, genesis).await;
-    let blockchain = init_blockchain(evm, store.clone(), blockchain_type);
+    let blockchain = init_blockchain(evm, store.clone(), blockchain_type, false);
     let path_metadata = metadata(path).expect("Failed to read path");
 
     // If it's an .rlp file it will be just one chain, but if it's a directory there can be multiple chains.
     let chains: Vec<Vec<Block>> = if path_metadata.is_dir() {
-        info!("Importing blocks from directory: {path}");
+        info!(path = %path, "Importing blocks from directory");
         let mut entries: Vec<_> = read_dir(path)
             .expect("Failed to read blocks directory")
             .map(|res| res.expect("Failed to open file in directory").path())
@@ -421,26 +422,36 @@ pub async fn import_blocks(
             .iter()
             .map(|entry| {
                 let path_str = entry.to_str().expect("Couldn't convert path to string");
-                info!("Importing blocks from chain file: {path_str}");
+                info!(path = %path_str, "Importing blocks from file");
                 utils::read_chain_file(path_str)
             })
             .collect()
     } else {
-        info!("Importing blocks from chain file: {path}");
+        info!(path = %path, "Importing blocks from file");
         vec![utils::read_chain_file(path)]
     };
 
+    let mut total_blocks_imported = 0;
     for blocks in chains {
         let size = blocks.len();
         let mut numbers_and_hashes = blocks
             .iter()
             .map(|b| (b.header.number, b.hash()))
             .collect::<Vec<_>>();
         // Execute block by block
-        for block in &blocks {
+        let mut last_progress_log = Instant::now();
+        for (index, block) in blocks.iter().enumerate() {
             let hash = block.hash();
             let number = block.header.number;
-            info!("Adding block {number} with hash {hash:#x}.");
+
+            // Log progress every 10 seconds
+            if last_progress_log.elapsed() >= Duration::from_secs(10) {
+                let processed = index + 1;
+                let percent = (((processed as f64 / size as f64) * 100.0) * 10.0).round() / 10.0;
+                info!(processed, total = size, percent, "Import progress");
+                last_progress_log = Instant::now();
+            }
+
             // Check if the block is already in the blockchain, if it is do nothing, if not add it
             let block_number = store.get_block_number(hash).await.map_err(|_e| {
                 ChainError::Custom(String::from(
@@ -476,8 +487,15 @@ pub async fn import_blocks(
                 .await?;
         }
 
-        info!("Added {size} blocks to blockchain");
+        total_blocks_imported += size;
     }
+
+    let total_duration = start_time.elapsed();
+    info!(
+        blocks = total_blocks_imported,
+        seconds = total_duration.as_secs_f64(),
+        "Import completed"
+    );
     Ok(())
 }
 
@@ -516,6 +534,8 @@ pub async fn export_blocks(
     let mut file = File::create(path).expect("Failed to open file");
     let mut buffer = vec![];
     let mut last_output = Instant::now();
+    // Denominator for percent completed; avoid division by zero
+    let denom = end.saturating_sub(start) + 1;
     for n in start..=end {
         let block = store
             .get_block_by_number(n)
@@ -526,11 +546,13 @@ pub async fn export_blocks(
         block.encode(&mut buffer);
         // Exporting the whole chain can take a while, so we need to show some output in the meantime
         if last_output.elapsed() > Duration::from_secs(5) {
-            info!("Exporting block {n}/{end}, {}% done", n * 100 / end);
+            let completed = n.saturating_sub(start) + 1;
+            let percent = (completed * 100) / denom;
+            info!(n, end, percent, "Exporting blocks");
             last_output = Instant::now();
         }
         file.write_all(&buffer).expect("Failed to write to file");
         buffer.clear();
     }
-    info!("Exported {} blocks to file {path}", end - start);
+    info!(blocks = end.saturating_sub(start), path = %path, "Exported blocks to file");
 }

cmd/ethrex/initializers.rs

@@ -35,7 +35,7 @@ use std::{
 };
 use tokio::sync::Mutex;
 use tokio_util::{sync::CancellationToken, task::TaskTracker};
-use tracing::{error, info, warn};
+use tracing::{debug, error, info, warn};
 use tracing_subscriber::{
     EnvFilter, Layer, Registry, filter::Directive, fmt, layer::SubscriberExt,
 };
@@ -115,9 +115,10 @@ pub fn init_blockchain(
     evm_engine: EvmEngine,
     store: Store,
     blockchain_type: BlockchainType,
+    perf_logs_enabled: bool,
 ) -> Arc<Blockchain> {
-    info!("Initiating blockchain with EVM: {}", evm_engine);
-    Blockchain::new(evm_engine, store, blockchain_type).into()
+    info!(evm = %evm_engine, "Initiating blockchain");
+    Blockchain::new(evm_engine, store, blockchain_type, perf_logs_enabled).into()
 }
 
 #[allow(clippy::too_many_arguments)]
@@ -250,7 +251,7 @@ pub fn get_bootnodes(opts: &Options, network: &Network, data_dir: &str) -> Vec<N
 
     bootnodes.extend(network.get_bootnodes());
 
-    info!("Reading known peers from config file");
+    debug!("Loading known peers from config");
 
     match read_node_config_file(data_dir) {
         Ok(Some(ref mut config)) => bootnodes.append(&mut config.known_peers),
@@ -312,7 +313,7 @@ pub fn get_local_p2p_node(opts: &Options, signer: &SecretKey) -> Node {
     // TODO Find a proper place to show node information
     // https://github.com/lambdaclass/ethrex/issues/836
     let enode = node.enode_url();
-    info!("Node: {enode}");
+    info!(enode = %enode, "Local node initialized");
 
     node
 }
@@ -384,7 +385,7 @@ pub async fn init_l1(
     #[cfg(feature = "sync-test")]
     set_sync_block(&store).await;
 
-    let blockchain = init_blockchain(opts.evm, store.clone(), BlockchainType::L1);
+    let blockchain = init_blockchain(opts.evm, store.clone(), BlockchainType::L1, true);
 
     let signer = get_signer(&data_dir);
 

cmd/ethrex/l2/initializers.rs

@@ -157,7 +157,7 @@ pub async fn init_l2(opts: L2Options) -> eyre::Result<()> {
     let store = init_store(&data_dir, genesis).await;
     let rollup_store = init_rollup_store(&rollup_store_dir).await;
 
-    let blockchain = init_blockchain(opts.node_opts.evm, store.clone(), BlockchainType::L2);
+    let blockchain = init_blockchain(opts.node_opts.evm, store.clone(), BlockchainType::L2, true);
 
     let signer = get_signer(&data_dir);
 
@@ -264,7 +264,7 @@ pub async fn init_l2(opts: L2Options) -> eyre::Result<()> {
     }
     info!("Server shut down started...");
     let node_config_path = PathBuf::from(data_dir + "/node_config.json");
-    info!("Storing config at {:?}...", node_config_path);
+    info!(path = %node_config_path.display(), "Storing node config");
     cancel_token.cancel();
     let node_config = NodeConfigFile::new(peer_table, local_node_record.lock().await.clone()).await;
     store_node_config_file(node_config, node_config_path).await;

crates/blockchain/blockchain.rs

@@ -64,6 +64,8 @@ pub struct Blockchain {
     /// This will be set to true once the initial sync has taken place and wont be set to false after
     /// This does not reflect whether there is an ongoing sync process
     is_synced: AtomicBool,
+    /// Whether performance logs should be emitted
+    pub perf_logs_enabled: bool,
     pub r#type: BlockchainType,
 }
 
@@ -86,13 +88,19 @@ fn log_batch_progress(batch_size: u32, current_block: u32) {
 }
 
 impl Blockchain {
-    pub fn new(evm_engine: EvmEngine, store: Store, blockchain_type: BlockchainType) -> Self {
+    pub fn new(
+        evm_engine: EvmEngine,
+        store: Store,
+        blockchain_type: BlockchainType,
+        perf_logs_enabled: bool,
+    ) -> Self {
         Self {
             evm_engine,
             storage: store,
             mempool: Mempool::new(),
             is_synced: AtomicBool::new(false),
             r#type: blockchain_type,
+            perf_logs_enabled,
         }
     }
 
@@ -103,6 +111,7 @@ impl Blockchain {
             mempool: Mempool::new(),
             is_synced: AtomicBool::new(false),
             r#type: BlockchainType::default(),
+            perf_logs_enabled: false,
         }
     }
 
@@ -411,7 +420,10 @@ impl Blockchain {
         let merkleized = Instant::now();
         let result = self.store_block(block, account_updates_list, res).await;
         let stored = Instant::now();
-        Self::print_add_block_logs(block, since, executed, merkleized, stored);
+
+        if self.perf_logs_enabled {
+            Self::print_add_block_logs(block, since, executed, merkleized, stored);
+        }
         result
     }
 
@@ -459,7 +471,7 @@ impl Blockchain {
                 "".to_string()
             };
 
-            info!("{}{}", base_log, extra_log);
+            debug!("{}{}", base_log, extra_log);
         }
     }
 
@@ -600,15 +612,17 @@ impl Blockchain {
             METRICS_BLOCKS.set_latest_gigagas(throughput);
         );
 
-        info!(
-            "[METRICS] Executed and stored: Range: {}, Last block num: {}, Last block gas limit: {}, Total transactions: {}, Total Gas: {}, Throughput: {} Gigagas/s",
-            blocks_len,
-            last_block_number,
-            last_block_gas_limit,
-            transactions_count,
-            total_gas_used,
-            throughput
-        );
+        if self.perf_logs_enabled {
+            info!(
+                "[METRICS] Executed and stored: Range: {}, Last block num: {}, Last block gas limit: {}, Total transactions: {}, Total Gas: {}, Throughput: {} Gigagas/s",
+                blocks_len,
+                last_block_number,
+                last_block_gas_limit,
+                transactions_count,
+                total_gas_used,
+                throughput
+            );
+        }
 
         Ok(())
     }

crates/storage/store.rs

@@ -24,7 +24,7 @@ use std::{
     collections::{BTreeMap, HashMap},
     sync::RwLock,
 };
-use tracing::{error, info, instrument};
+use tracing::{debug, error, info, instrument};
 /// Number of state trie segments to fetch concurrently during state sync
 pub const STATE_TRIE_SEGMENTS: usize = 2;
 /// Maximum amount of reads from the snapshot in a single transaction to avoid performance hits due to long-living reads
@@ -73,12 +73,12 @@ impl Store {
         self.engine.apply_updates(update_batch).await
     }
 
-    pub fn new(_path: &str, engine_type: EngineType) -> Result<Self, StoreError> {
-        info!("Starting storage engine ({engine_type:?})");
+    pub fn new(path: &str, engine_type: EngineType) -> Result<Self, StoreError> {
+        info!(engine = ?engine_type, path = %path, "Opening storage engine");
         let store = match engine_type {
             #[cfg(feature = "libmdbx")]
             EngineType::Libmdbx => Self {
-                engine: Arc::new(LibmdbxStore::new(_path)?),
+                engine: Arc::new(LibmdbxStore::new(path)?),
                 chain_config: Default::default(),
                 latest_block_header: Arc::new(RwLock::new(BlockHeader::default())),
             },
@@ -89,7 +89,6 @@ impl Store {
             },
         };
 
-        info!("Started store engine");
         Ok(store)
     }
 
@@ -569,7 +568,7 @@ impl Store {
     }
 
     pub async fn add_initial_state(&self, genesis: Genesis) -> Result<(), StoreError> {
-        info!("Storing initial state from genesis");
+        debug!("Storing initial state from genesis");
 
         // Obtain genesis block
         let genesis_block = genesis.get_block();
@@ -613,10 +612,7 @@ impl Store {
         debug_assert_eq!(genesis_state_root, genesis_block.header.state_root);
 
         // Store genesis block
-        info!(
-            "Storing genesis block with number {} and hash {}",
-            genesis_block_number, genesis_hash
-        );
+        info!(hash = %genesis_hash, "Storing genesis block");
 
         self.add_block(genesis_block).await?;
         self.update_earliest_block_number(genesis_block_number)

fixtures/network/hoodi.yaml

@@ -1,6 +1,6 @@
 participants:
   - el_type: ethrex
-    el_image: ethrex:latest
+    el_image: ethrex:local
     cl_type: lighthouse
     cl_image: sigp/lighthouse:v7.0.1
     count: 1

tooling/ef_tests/blockchain/test_runner.rs

@@ -97,7 +97,7 @@ pub async fn run_ef_test(
     check_prestate_against_db(test_key, test, &store);
 
     // Blockchain EF tests are meant for L1.
-    let blockchain = Blockchain::new(evm, store.clone(), BlockchainType::L1);
+    let blockchain = Blockchain::new(evm, store.clone(), BlockchainType::L1, false);
 
     // Early return if the exception is in the rlp decoding of the block
     for bf in &test.blocks {