Fix weight limits in evm tracing runtimes (#3210)

* Improve tracing logs and fix the transaction indexes in evm traces

* fix block weight limits in evm tracing runtimes

* re-add comment

* improve compilation error

* small improvement

* test weight limits in tracing

* disable evm-tracing feature when running unit tests

* Revert unecessary changes
This reverts commit a58f24a.

* update lock file

* Add minimal fix

* Also reset block weights when tracing a specific transaction

client/evm-tracing/Cargo.toml

@@ -12,6 +12,7 @@ ethereum-types = { workspace = true, features = [ "std" ] }
 hex = { workspace = true, features = [ "serde" ] }
 serde = { workspace = true, features = [ "derive", "std" ] }
 serde_json = { workspace = true, default-features = true }
+log = { workspace = true }
 
 # Moonbeam
 evm-tracing-events = { workspace = true, features = [ "std" ] }

client/evm-tracing/src/formatters/call_tracer.rs

@@ -36,12 +36,18 @@ impl super::ResponseFormatter for Formatter {
 	type Listener = Listener;
 	type Response = Vec<BlockTransactionTrace>;
 
-	fn format(mut listener: Listener) -> Option<Vec<BlockTransactionTrace>> {
-		// Remove empty BTreeMaps pushed to `entries`.
-		// I.e. InvalidNonce or other pallet_evm::runner exits
-		listener.entries.retain(|x| !x.is_empty());
+	fn format(listener: Listener) -> Option<Vec<BlockTransactionTrace>> {
 		let mut traces = Vec::new();
 		for (eth_tx_index, entry) in listener.entries.iter().enumerate() {
+			// Skip empty BTreeMaps pushed to `entries`.
+			// I.e. InvalidNonce or other pallet_evm::runner exits
+			if entry.is_empty() {
+				log::debug!(
+					target: "tracing",
+					"Empty trace entry with transaction index {}, skipping...", eth_tx_index
+				);
+				continue;
+			}
 			let mut result: Vec<Call> = entry
 				.into_iter()
 				.map(|(_, it)| {

client/evm-tracing/src/formatters/trace_filter.rs

@@ -30,12 +30,18 @@ impl super::ResponseFormatter for Formatter {
 	type Listener = Listener;
 	type Response = Vec<TransactionTrace>;
 
-	fn format(mut listener: Listener) -> Option<Vec<TransactionTrace>> {
-		// Remove empty BTreeMaps pushed to `entries`.
-		// I.e. InvalidNonce or other pallet_evm::runner exits
-		listener.entries.retain(|x| !x.is_empty());
+	fn format(listener: Listener) -> Option<Vec<TransactionTrace>> {
 		let mut traces = Vec::new();
 		for (eth_tx_index, entry) in listener.entries.iter().enumerate() {
+			// Skip empty BTreeMaps pushed to `entries`.
+			// I.e. InvalidNonce or other pallet_evm::runner exits
+			if entry.is_empty() {
+				log::debug!(
+					target: "tracing",
+					"Empty trace entry with transaction index {}, skipping...", eth_tx_index
+				);
+				continue;
+			}
 			let mut tx_traces: Vec<_> = entry
 				.into_iter()
 				.map(|(_, trace)| match trace.inner.clone() {

client/rpc/trace/src/lib.rs

@@ -803,7 +803,7 @@ where
 					substrate_hash, e
 				)
 			})?
-			.ok_or_else(|| format!("Subtrate block {} don't exist", substrate_hash))?;
+			.ok_or_else(|| format!("Substrate block {} don't exist", substrate_hash))?;
 
 		let height = *block_header.number();
 		let substrate_parent_hash = *block_header.parent_hash();
@@ -890,6 +890,7 @@ where
 				.map_err(|e| format!("Blockchain error when replaying block {} : {:?}", height, e))?
 				.map_err(|e| {
 					tracing::warn!(
+						target: "tracing",
 						"Internal runtime error when replaying block {} : {:?}",
 						height,
 						e
@@ -935,6 +936,7 @@ where
 						}
 						None => {
 							log::warn!(
+								target: "tracing",
 								"A trace in block {} does not map to any known ethereum transaction. Trace: {:?}",
 								height,
 								trace,

runtime/common/src/apis.rs

@@ -173,6 +173,14 @@ macro_rules! impl_runtime_apis_plus_common {
 						for ext in extrinsics.into_iter() {
 							let _ = match &ext.0.function {
 								RuntimeCall::Ethereum(transact { transaction }) => {
+
+									// Reset the previously consumed weight when tracing ethereum transactions.
+									// This is necessary because EVM tracing introduces additional
+									// (ref_time) overhead, which differs from the production runtime behavior.
+									// Without resetting the block weight, the extra tracing overhead could
+									// leading to some transactions to incorrectly fail during tracing.
+									frame_system::BlockWeight::<Runtime>::kill();
+
 									if transaction == traced_transaction {
 										EvmTracer::new().trace(|| Executive::apply_extrinsic(ext));
 										return Ok(());
@@ -249,16 +257,47 @@ macro_rules! impl_runtime_apis_plus_common {
 						for ext in extrinsics.into_iter() {
 							match &ext.0.function {
 								RuntimeCall::Ethereum(transact { transaction }) => {
-									if known_transactions.contains(&transaction.hash()) {
+
+									// Reset the previously consumed weight when tracing multiple transactions.
+									// This is necessary because EVM tracing introduces additional
+									// (ref_time) overhead, which differs from the production runtime behavior.
+									// Without resetting the block weight, the extra tracing overhead could
+									// leading to some transactions to incorrectly fail during tracing.
+									frame_system::BlockWeight::<Runtime>::kill();
+
+									let tx_hash = &transaction.hash();
+									if known_transactions.contains(&tx_hash) {
 										// Each known extrinsic is a new call stack.
 										EvmTracer::emit_new();
-										EvmTracer::new().trace(|| Executive::apply_extrinsic(ext));
+										EvmTracer::new().trace(|| {
+											if let Err(err) = Executive::apply_extrinsic(ext) {
+												log::debug!(
+													target: "tracing",
+													"Could not trace eth transaction (hash: {}): {:?}",
+													&tx_hash,
+													err
+												);
+											}
+										});
 									} else {
-										let _ = Executive::apply_extrinsic(ext);
+										if let Err(err) = Executive::apply_extrinsic(ext) {
+											log::debug!(
+												target: "tracing",
+												"Failed to apply eth extrinsic (hash: {}): {:?}",
+												&tx_hash,
+												err
+											);
+										}
 									}
 								}
 								_ => {
-									let _ = Executive::apply_extrinsic(ext);
+									if let Err(err) = Executive::apply_extrinsic(ext) {
+										log::debug!(
+											target: "tracing",
+											"Failed to apply non-eth extrinsic: {:?}",
+											err
+										);
+									}
 								}
 							};
 						}

test/suites/tracing-tests/test-trace-filter-weight-limits.ts

@@ -0,0 +1,76 @@
+import { afterAll, customDevRpcRequest, describeSuite, expect } from "@moonwall/cli";
+import { ALITH_ADDRESS, createEthersTransaction } from "@moonwall/util";
+import { sleep } from "../../helpers";
+import { encodeFunctionData } from "viem";
+
+describeSuite({
+  id: "T18",
+  title: "Trace filter - Test block weight limits with evm-tracing enabled",
+  foundationMethods: "dev",
+  testCases: ({ context, it }) => {
+    afterAll(async () => {
+      await sleep(500); // Add sleep to allow for graceful teardown
+    });
+
+    it({
+      id: "T01",
+      title:
+        "The number of unique transaction traces should be the same as the number of transactions included in a block",
+      test: async function () {
+        const { abi, contractAddress } = await context.deployContract!("BloatedContract");
+
+        let nonce = await context.viem().getTransactionCount({ address: ALITH_ADDRESS });
+        const tx = [];
+        for (let i = 0; i < 500; i++) {
+          tx.push(
+            await createEthersTransaction(context, {
+              to: contractAddress,
+              data: encodeFunctionData({ abi, functionName: "doSomething", args: [] }),
+              gasLimit: 10_000_000,
+              nonce: nonce++,
+            })
+          );
+        }
+
+        const substrateBlock = await context.createBlock(tx, { allowFailures: false });
+        const txHashes = (substrateBlock.result || [])
+          .filter((result) => result.successful)
+          .map((result) => result.hash);
+
+        const blockNumber = (await context.polkadotJs().query.ethereum.currentBlock())
+          .unwrap()
+          .header.number.toNumber();
+        const blockNumberHex = blockNumber.toString(16);
+        const ethBlock = await customDevRpcRequest("eth_getBlockByNumber", [blockNumberHex, false]);
+
+        // Confirm that all transactions were included in the ethereum block
+        expect(ethBlock.transactions.length).to.equal(txHashes.length);
+
+        const traceFilterResponse = await customDevRpcRequest("trace_filter", [
+          {
+            fromBlock: blockNumberHex,
+            toBlock: blockNumberHex,
+          },
+        ]);
+        const uniqueTxsInTraces = Object.keys(
+          traceFilterResponse.reduce(
+            (prev, cur) => ({
+              ...prev,
+              [cur.transactionHash]: true,
+            }),
+            {}
+          )
+        );
+
+        console.log(`
+          Ethereum transactions count: ${ethBlock.transactions.length},
+          Ethereum traces count: ${traceFilterResponse.length},
+          Ethereum unique transactions in traces count: ${uniqueTxsInTraces.length}
+       `);
+
+        // Assert that all eth transactions were traced
+        expect(ethBlock.transactions.length).to.equal(uniqueTxsInTraces.length);
+      },
+    });
+  },
+});