Remove the need of tests to sleep after manual mining

crates/anvil-polkadot/Cargo.toml

@@ -145,6 +145,7 @@ tokio-stream = "0.1.17"
 jsonrpsee = "0.24.10"
 sqlx = "0.8.6"
 revm.workspace = true
+datetime = "0.5.2"
 
 [dev-dependencies]
 alloy-provider = { workspace = true, features = ["txpool-api"] }

crates/anvil-polkadot/src/api_server/server.rs

@@ -41,6 +41,7 @@ use alloy_serde::WithOtherFields;
 use alloy_trie::{EMPTY_ROOT_HASH, KECCAK_EMPTY, TrieAccount};
 use anvil_core::eth::{EthRequest, Params as MineParams};
 use anvil_rpc::response::ResponseResult;
+use chrono::{DateTime, Datelike, Utc};
 use codec::{Decode, Encode};
 use futures::{StreamExt, channel::mpsc};
 use indexmap::IndexMap;
@@ -391,7 +392,7 @@ impl ApiServer {
             ));
         }
 
-        // Subscribe to new block only when automine is enabled.
+        // Subscribe to new best blocks.
         let receiver = self.eth_rpc_client.block_notifier().map(|sender| sender.subscribe());
 
         let awaited_hash = self
@@ -400,7 +401,7 @@ impl ApiServer {
             .await
             .map_err(Error::Mining)?;
         // Wait for the transaction to be included in a block if automine is enabled
-        wait_for_hash(receiver, awaited_hash).await?;
+        self.wait_for_hash(receiver, awaited_hash).await?;
         Ok(())
     }
 
@@ -433,10 +434,10 @@ impl ApiServer {
     async fn evm_mine(&self, mine: Option<MineParams<Option<MineOptions>>>) -> Result<String> {
         node_info!("evm_mine");
 
-        // Subscribe to new block only when automine is enabled.
+        // Subscribe to new best blocks.
         let receiver = self.eth_rpc_client.block_notifier().map(|sender| sender.subscribe());
         let awaited_hash = self.mining_engine.evm_mine(mine.and_then(|p| p.params)).await?;
-        wait_for_hash(receiver, awaited_hash).await?;
+        self.wait_for_hash(receiver, awaited_hash).await?;
         Ok("0x0".to_string())
     }
 
@@ -446,14 +447,13 @@ impl ApiServer {
     ) -> Result<Vec<Block>> {
         node_info!("evm_mine_detailed");
 
-        // Subscribe to new block only when automine is enabled.
+        // Subscribe to new best blocks.
         let receiver = self.eth_rpc_client.block_notifier().map(|sender| sender.subscribe());
 
-        let result = self.mining_engine.do_evm_mine(mine.and_then(|p| p.params)).await?;
-        let mined_blocks = result.0;
-        let awaited_hash = result.1;
+        let (mined_blocks, awaited_hash) =
+            self.mining_engine.do_evm_mine(mine.and_then(|p| p.params)).await?;
 
-        wait_for_hash(receiver, awaited_hash).await?;
+        self.wait_for_hash(receiver, awaited_hash).await?;
 
         let mut blocks = Vec::with_capacity(mined_blocks as usize);
         let last_block = self.client.info().best_number as u64;
@@ -1475,6 +1475,59 @@ impl ApiServer {
 
         Ok(())
     }
+
+    async fn wait_for_hash(
+        &self,
+        receiver: Option<tokio::sync::broadcast::Receiver<H256>>,
+        awaited_hash: H256,
+    ) -> Result<()> {
+        if let Some(mut receiver) = receiver {
+            tokio::time::timeout(Duration::from_millis(500), async {
+                loop {
+                    if let Ok(block_hash) = receiver.recv().await {
+                        if let Err(e) = self.log_mined_block(block_hash).await {
+                            node_info!("Failed to log mined block {block_hash:?}: {e:?}");
+                        }
+                        if block_hash == awaited_hash {
+                            break;
+                        }
+                    }
+                }
+            })
+            .await
+            .map_err(|e| {
+                Error::InternalError(format!(
+                    "Was not notified about the new best block in time {e:?}."
+                ))
+            })?;
+        }
+        Ok(())
+    }
+
+    async fn log_mined_block(&self, block_hash: H256) -> Result<()> {
+        let block_timestamp = self.backend.read_timestamp(block_hash)?;
+        let block_number = self.backend.read_block_number(block_hash)?;
+        let timestamp = utc_from_millis(block_timestamp)?;
+        node_info!("    Block Number: {}", block_number);
+        node_info!("    Block Hash: {:?}", block_hash);
+        if timestamp.year() > 9999 {
+            // rf2822 panics with more than 4 digits
+            node_info!("    Block Time: {:?}\n", timestamp.to_rfc3339());
+        } else {
+            node_info!("    Block Time: {:?}\n", timestamp.to_rfc2822());
+        }
+        Ok(())
+    }
+}
+
+/// Returns the `Utc` datetime for the given seconds since unix epoch
+fn utc_from_millis(millis: u64) -> Result<DateTime<Utc>> {
+    DateTime::from_timestamp_millis(
+        millis.try_into().map_err(|err| {
+            Error::InvalidParams(format!("Could not convert the timestamp: {err:?}"))
+        })?,
+    )
+    .ok_or(Error::InvalidParams("Could not get the utc datetime 😭".to_string()))
 }
 
 fn new_contract_info(address: &Address, code_hash: H256, nonce: Nonce) -> ContractInfo {
@@ -1622,27 +1675,3 @@ async fn create_revive_rpc_client(
 
     Ok(eth_rpc_client)
 }
-
-async fn wait_for_hash(
-    receiver: Option<tokio::sync::broadcast::Receiver<H256>>,
-    awaited_hash: H256,
-) -> Result<()> {
-    if let Some(mut receiver) = receiver {
-        tokio::time::timeout(Duration::from_millis(500), async {
-            loop {
-                if let Ok(block_hash) = receiver.recv().await {
-                    if block_hash == awaited_hash {
-                        break;
-                    }
-                }
-            }
-        })
-        .await
-        .map_err(|e| {
-            Error::InternalError(format!(
-                "Was not notified about the new best block in time {e:?}."
-            ))
-        })?;
-    }
-    Ok(())
-}

crates/anvil-polkadot/src/substrate_node/service/backend.rs

@@ -30,6 +30,8 @@ pub enum BackendError {
     MissingAuraAuthorities,
     #[error("Could not find timestamp in the state")]
     MissingTimestamp,
+    #[error("Could not find block number in the state")]
+    MissingBlockNumber,
     #[error("Unable to decode total issuance {0}")]
     DecodeTotalIssuance(codec::Error),
     #[error("Unable to decode chain id {0}")]
@@ -44,6 +46,8 @@ pub enum BackendError {
     DecodeCodeInfo(codec::Error),
     #[error("Unable to decode timestamp: {0}")]
     DecodeTimestamp(codec::Error),
+    #[error("Unable to decode blockNumber: {0}")]
+    DecodeBlockNumber(codec::Error),
     #[error("Unable to decode aura authorities: {0}")]
     DecodeAuraAuthorities(codec::Error),
 }
@@ -72,6 +76,13 @@ impl BackendWithOverlay {
         u64::decode(&mut &value[..]).map_err(BackendError::DecodeTimestamp)
     }
 
+    pub fn read_block_number(&self, hash: Hash) -> Result<u32> {
+        let key = well_known_keys::BLOCK_NUMBER_KEY;
+        let value =
+            self.read_top_state(hash, key.to_vec())?.ok_or(BackendError::MissingBlockNumber)?;
+        u32::decode(&mut &value[..]).map_err(BackendError::DecodeBlockNumber)
+    }
+
     pub fn read_chain_id(&self, hash: Hash) -> Result<u64> {
         let key = well_known_keys::CHAIN_ID;
 

crates/anvil-polkadot/tests/it/genesis.rs

@@ -54,7 +54,6 @@ async fn test_genesis_params() {
 
     let latest_block_number = node.best_block_number().await;
     assert_eq!(latest_block_number, genesis_block_number + 2);
-    tokio::time::sleep(Duration::from_millis(400)).await;
     assert_eq!(node.eth_best_block().await.number.as_u32(), genesis_block_number + 2);
 
     let hash2 = node.block_hash_by_number(genesis_block_number + 2).await.unwrap();